Attachment 1453896 Details for Bug 1594454 – Nova compute debug logs

Nova compute debug logs

nova-compute.log (text/plain), 213.55 KB, created by Cody Swanson on 2018-06-23 05:31:43 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Cody Swanson

Created: 2018-06-23 05:31:43 UTC

Size: 213.55 KB

patch

obsolete

>2018-06-22 22:10:16.819 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:10:16.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:10:16.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5758
>2018-06-22 22:10:16.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 569f6b5c70684b91967e0cb6340ae376 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:16.856 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 569f6b5c70684b91967e0cb6340ae376 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:16.858 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:10:16.859 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:10:16.859 183819 DEBUG nova.objects.instance [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lazy-loading 'info_cache' on Instance uuid 377c527e-4693-4bf4-956b-741c82d6bc39 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1013
>2018-06-22 22:10:16.860 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: dce36cf95d804fa49d52c37d2a570a74 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:16.917 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: dce36cf95d804fa49d52c37d2a570a74 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:16.920 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: c3aeac9240534054bcf798dcb294d978 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:16.933 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: c3aeac9240534054bcf798dcb294d978 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:16.985 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=377c527e-4693-4bf4-956b-741c82d6bc39 used request id req-17ab6a70-aa08-4fb3-8083-9ea9c8014fec _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:10:17.063 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-a0e21b28-ffaf-45e3-8ed1-c2f3b91dfc95 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:10:17.141 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-076a13d5-dd53-4d70-9b20-739b5cf70a2e _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:10:17.142 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:10:17.142 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:10:17.143 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 902f4bc4c294449eb218a0947957094d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:17.145 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 857711f4e402418bb33e2325bc284f89 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:17.159 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 902f4bc4c294449eb218a0947957094d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:17.160 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:10:17.161 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:10:17.163 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 857711f4e402418bb33e2325bc284f89 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:27.145 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 0115f8a84f7d4d8182c8e162e92ef722 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:27.161 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:10:27.162 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:10:27.164 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 0115f8a84f7d4d8182c8e162e92ef722 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:37.147 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: a2ae3973c6404bd1927ceb6af74586c1 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:37.167 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a2ae3973c6404bd1927ceb6af74586c1 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:42.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:10:47.149 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: b5b89ce6b6664b91b0dd23163f3519fb exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:47.167 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b5b89ce6b6664b91b0dd23163f3519fb __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:57.150 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: ca525e30fd38445fa2232b883e011da7 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:57.169 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ca525e30fd38445fa2232b883e011da7 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:58.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:10:58.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 3cf3dedec9dd45d3b19f390580b80c1f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:58.844 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3cf3dedec9dd45d3b19f390580b80c1f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:58.848 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:10:58.895 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 5ed95fe110f046bd9bfc666f8b05b8b5 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:58.937 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 5ed95fe110f046bd9bfc666f8b05b8b5 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:58.941 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b31dde2ab75f4a3baa4294201a5ff325 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:58.959 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b31dde2ab75f4a3baa4294201a5ff325 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:58.962 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:10:58.963 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:10:59.016 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:10:59.016 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6602MB free_disk=102GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:10:59.017 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:10:59.020 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b38d9e42448744098ac6b61871392002 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:59.049 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b38d9e42448744098ac6b61871392002 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:59.051 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:10:59.052 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 0473740ffca34629a28b23ac71776819 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:59.093 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 0473740ffca34629a28b23ac71776819 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:59.099 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 03aa90d082024f6db946f0d80e5d706b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:59.113 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 03aa90d082024f6db946f0d80e5d706b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:59.118 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 76fa6138697542da8a29c86422fae46b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:59.134 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 76fa6138697542da8a29c86422fae46b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:59.137 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] No authentication information found for placement API. Placement is optional in Newton, but required in Ocata. Please enable the placement service before upgrading.
>2018-06-22 22:10:59.138 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 2f3762d8394f4d44b8861acf33ffc62c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:59.200 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 2f3762d8394f4d44b8861acf33ffc62c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:59.202 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:10:59.202 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:10:59.209 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 7a1cd31728ad4f98adfe581654f18262 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:10:59.235 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7a1cd31728ad4f98adfe581654f18262 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:10:59.237 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:10:59.238 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:10:59.238 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.221s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:11:00.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._run_pending_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:00.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Cleaning up deleted instances _run_pending_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6774
>2018-06-22 22:11:00.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b9a3af0ef9224197836519d9c4db7c44 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:00.857 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b9a3af0ef9224197836519d9c4db7c44 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:00.858 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] There are 0 instances to clean _run_pending_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6783
>2018-06-22 22:11:06.817 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:06.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:07.152 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: d1923458ffde4360b455ea6c10e2c80c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:07.169 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d1923458ffde4360b455ea6c10e2c80c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:12.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:12.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:11:13.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:13.823 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 33ca129a534a4b0d90fc475b0a906f54 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:13.841 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 33ca129a534a4b0d90fc475b0a906f54 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:16.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:16.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:11:16.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: fb8b242e62b244d7bf269f74db219a5a exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:16.903 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: fb8b242e62b244d7bf269f74db219a5a __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:16.906 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-332d5e73-d056-4625-a1df-8eae908c89cf" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:11:16.907 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:11:16.908 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: ddfb72a46c2c4a07bd8b141e8cdc48e8 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:16.920 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ddfb72a46c2c4a07bd8b141e8cdc48e8 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:16.972 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=332d5e73-d056-4625-a1df-8eae908c89cf used request id req-609ab911-e9e3-418a-9902-cfed6613f97d _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:11:17.008 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-1446e67e-9186-4047-837d-51e830111670 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:11:17.036 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-e7923652-6fcf-4c85-9afd-a60042fe11ec _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:11:17.037 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:11:17.037 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:11:17.038 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b4db63808ede400eb23c4d80c1ee0667 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:17.055 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b4db63808ede400eb23c4d80c1ee0667 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:17.056 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-332d5e73-d056-4625-a1df-8eae908c89cf" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:11:17.057 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:11:17.152 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: f69e9e96c6eb4031b18c0c16ddf00b91 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:17.171 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: f69e9e96c6eb4031b18c0c16ddf00b91 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:27.059 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:27.060 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:27.154 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 25a5db2f57804d548602873bf71c91be exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:27.175 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 25a5db2f57804d548602873bf71c91be __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:37.158 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 560ef89d652d408d94cb1dec2f8c8e0b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:37.176 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 560ef89d652d408d94cb1dec2f8c8e0b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:43.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:47.158 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 282643f5dcd246f7b07f5b53a896de8b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:47.179 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 282643f5dcd246f7b07f5b53a896de8b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:48.815 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._sync_scheduler_instance_info run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:48.817 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 918d62de466f43c5bf5af3ce8f4b8577 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:48.855 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 918d62de466f43c5bf5af3ce8f4b8577 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:48.859 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CAST unique_id: e2a787096a3541f89068103ea92d1025 FANOUT topic 'scheduler' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:557
>2018-06-22 22:11:57.162 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 18af41b0481a4776ab1512fdc0d597fe exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:57.182 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 18af41b0481a4776ab1512fdc0d597fe __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:58.868 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:11:58.869 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 4d1e242fd07242329e91034dad8ce706 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:58.888 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 4d1e242fd07242329e91034dad8ce706 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:58.894 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:11:58.941 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: ec7c988809194e04a49876ff8f1fdd0f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:58.982 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ec7c988809194e04a49876ff8f1fdd0f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:58.986 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 981eed53e9d543e9922e554a06cff164 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.004 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 981eed53e9d543e9922e554a06cff164 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.007 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:11:59.010 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:11:59.075 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:11:59.076 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6602MB free_disk=102GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:11:59.076 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:11:59.079 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 6009aa851dd54b629d32d4cdb2b9869a exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.105 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6009aa851dd54b629d32d4cdb2b9869a __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.107 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:11:59.108 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 05f1bbcaa0c848b4903c7f7fd2f9bbe0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.155 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 05f1bbcaa0c848b4903c7f7fd2f9bbe0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.160 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: caaef9dc090b498cb5cbc656bb5064c0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.175 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: caaef9dc090b498cb5cbc656bb5064c0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.179 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 7181dd2496b14126ae37ab068685f1dd exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.195 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7181dd2496b14126ae37ab068685f1dd __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.198 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: a2e2b5bed8704263806afca4b942df4d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.242 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a2e2b5bed8704263806afca4b942df4d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.243 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:11:59.244 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:11:59.250 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 55f3bb7586314a23bdec1f9606423719 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:11:59.274 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 55f3bb7586314a23bdec1f9606423719 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:11:59.276 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:11:59.277 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:11:59.277 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.200s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:12:07.165 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: b66fadb9fe894e34b00b84e7e3e48716 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:07.186 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b66fadb9fe894e34b00b84e7e3e48716 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:08.815 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:08.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:12.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:12.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:12:14.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:14.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 099423fa53a44f8894c62d5ac78ac512 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:14.839 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 099423fa53a44f8894c62d5ac78ac512 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:17.168 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: b89975c0851747c2b28221e6d995909f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:17.187 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b89975c0851747c2b28221e6d995909f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:17.819 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:17.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:12:17.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5758
>2018-06-22 22:12:17.821 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 6e28dd1499f8474d881ae2f7917d2780 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:17.855 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6e28dd1499f8474d881ae2f7917d2780 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:17.858 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:12:17.858 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:12:17.859 183819 DEBUG nova.objects.instance [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lazy-loading 'info_cache' on Instance uuid 377c527e-4693-4bf4-956b-741c82d6bc39 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1013
>2018-06-22 22:12:17.860 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 506ec2d164cc416caafbef5dbad4ece2 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:17.918 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 506ec2d164cc416caafbef5dbad4ece2 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:17.921 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 121bb61d8d1c4083a80255c9eb172d3d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:17.938 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 121bb61d8d1c4083a80255c9eb172d3d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:18.286 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=377c527e-4693-4bf4-956b-741c82d6bc39 used request id req-5f5640ac-545a-4614-b62b-c6b3d6baa026 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:12:18.375 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-f36eacd0-a874-4b08-a64b-ae19933f009b _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:12:18.455 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-1347d44d-2de6-4b82-b482-e33b539e0797 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:12:18.456 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:12:18.456 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:12:18.458 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: e83ffc332f994bc7802b52773b7c8bfe exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:18.475 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e83ffc332f994bc7802b52773b7c8bfe __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:18.477 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:12:18.477 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:12:27.169 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: c086069e250e4734975daf9f76c6b3b9 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:27.192 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: c086069e250e4734975daf9f76c6b3b9 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:28.478 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:28.479 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:31.313 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received message with unique_id: 1c82c492105c45d2b9551b2905997047 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:269
>2018-06-22 22:12:31.320 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 691c4d65fb314a3199e87d765fe6fb75 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:31.436 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 691c4d65fb314a3199e87d765fe6fb75 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:31.438 183819 DEBUG nova.compute.manager [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:12:31.444 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 8039c4fe5b76459ca4fa7821b7cfcb14 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:31.572 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8039c4fe5b76459ca4fa7821b7cfcb14 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:31.574 183819 INFO nova.compute.manager [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] instance snapshotting
>2018-06-22 22:12:31.576 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: 10a416e65dee4b7c8ead2e3141259d8b NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:12:31.980 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727151.98, 332d5e73-d056-4625-a1df-8eae908c89cf => Paused> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:12:31.981 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] VM Paused (Lifecycle Event)
>2018-06-22 22:12:31.982 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: d4478aa2063843cb804c0b25c249dd14 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:32.040 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d4478aa2063843cb804c0b25c249dd14 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:32.042 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:12:32.046 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Synchronizing instance power state after lifecycle event "Paused"; current vm_state: active, current task_state: image_snapshot, current DB power_state: 1, VM power_state: 3 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:12:32.049 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: f83f02a627964baa8b9464106b1e8810 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:32.118 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: f83f02a627964baa8b9464106b1e8810 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:32.119 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] During sync_power_state the instance has a pending task (image_snapshot). Skip.
>2018-06-22 22:12:32.432 183819 INFO nova.virt.libvirt.driver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Beginning cold snapshot process
>2018-06-22 22:12:32.436 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: c4739a263410428eadcfa271e535157f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:32.555 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: c4739a263410428eadcfa271e535157f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:32.559 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 01b5ccc6912a4df0a2408bda25a669cd exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:32.675 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 01b5ccc6912a4df0a2408bda25a669cd __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:32.740 183819 DEBUG nova.virt.libvirt.imagebackend [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] No parent info for f7593a43-5674-4b26-933a-5aa74821dd21; asking the Image API where its store is _get_parent_pool /usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py:950
>2018-06-22 22:12:32.868 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] creating snapshot(9bf02835d6634043a71e82d72acb7340) on rbd image(332d5e73-d056-4625-a1df-8eae908c89cf_disk) create_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:382
>2018-06-22 22:12:33.001 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] cloning vms/332d5e73-d056-4625-a1df-8eae908c89cf_disk@9bf02835d6634043a71e82d72acb7340 to images/21476964-00e7-482f-9c99-7110ae2d404f clone /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:231
>2018-06-22 22:12:33.076 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] flattening images/21476964-00e7-482f-9c99-7110ae2d404f flatten /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:281
>2018-06-22 22:12:37.165 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 43f02f5199ab420d83fe150159496dc3 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:37.193 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 43f02f5199ab420d83fe150159496dc3 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:37.926 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] removing snapshot(9bf02835d6634043a71e82d72acb7340) on rbd image(332d5e73-d056-4625-a1df-8eae908c89cf_disk) remove_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:410
>2018-06-22 22:12:38.321 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] creating snapshot(snap) on rbd image(21476964-00e7-482f-9c99-7110ae2d404f) create_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:382
>2018-06-22 22:12:39.628 183819 DEBUG nova.virt.libvirt.host [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Removed pending event for 332d5e73-d056-4625-a1df-8eae908c89cf due to lifecycle event _event_emit_delayed /usr/lib/python2.7/site-packages/nova/virt/libvirt/host.py:303
>2018-06-22 22:12:39.629 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727159.63, 332d5e73-d056-4625-a1df-8eae908c89cf => Started> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:12:39.629 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] VM Started (Lifecycle Event)
>2018-06-22 22:12:39.630 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 59a4aafb7e394e7cb75afa5c2df10770 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:39.694 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 59a4aafb7e394e7cb75afa5c2df10770 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:39.696 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:12:39.701 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Synchronizing instance power state after lifecycle event "Started"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:12:39.703 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: e3cabeebbc804b41babe68bf9c8488cd exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:39.894 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e3cabeebbc804b41babe68bf9c8488cd __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:39.895 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:12:39.896 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727159.63, 332d5e73-d056-4625-a1df-8eae908c89cf => Resumed> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:12:39.896 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] VM Resumed (Lifecycle Event)
>2018-06-22 22:12:39.898 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: f8529e3507604366959032093e113c4c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:39.970 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: f8529e3507604366959032093e113c4c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:39.972 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:12:39.976 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Synchronizing instance power state after lifecycle event "Resumed"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:12:39.978 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 4148d11e5ee541cb8908f190b28e5836 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:40.036 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 4148d11e5ee541cb8908f190b28e5836 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:40.037 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:12:40.464 183819 INFO nova.virt.libvirt.driver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Snapshot image upload complete
>2018-06-22 22:12:40.468 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 534cef961e0e4395b1611d802f798bb3 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:40.582 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 534cef961e0e4395b1611d802f798bb3 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:40.587 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-a8a52f39-32c7-4ec7-8310-a353525d13e9 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: 298ea94ad66d44f392cee003db27cd22 NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:12:43.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:12:47.165 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 4e84e20ae59d48dd86d9d694696b0162 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:47.183 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 4e84e20ae59d48dd86d9d694696b0162 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:12:57.166 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: bee8a73afb464244b85aba06cc338cd9 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:12:57.187 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: bee8a73afb464244b85aba06cc338cd9 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:00.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:00.821 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 3f167e5a770445d8a7ea1a10820d556f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:00.842 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3f167e5a770445d8a7ea1a10820d556f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:00.847 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:13:00.900 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: db77ebf776634e5482d20d5b927ac2f3 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:00.944 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: db77ebf776634e5482d20d5b927ac2f3 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:00.948 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b4e7bb13eb52455d9635850a0339e758 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:00.967 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b4e7bb13eb52455d9635850a0339e758 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:00.970 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:13:00.972 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:13:01.026 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:13:01.026 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6667MB free_disk=99GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:13:01.027 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:13:01.029 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 34f5169d712142f9b60bf2a553afdf39 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:01.070 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 34f5169d712142f9b60bf2a553afdf39 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:01.072 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] No authentication information found for placement API. Placement is optional in Newton, but required in Ocata. Please enable the placement service before upgrading.
>2018-06-22 22:13:01.073 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:13:01.074 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 5a78ce0de24544d2ae3191888fcefbc6 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:01.122 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 5a78ce0de24544d2ae3191888fcefbc6 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:01.129 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: ef5eb9e896964e5f8857d144718f145c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:01.145 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ef5eb9e896964e5f8857d144718f145c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:01.151 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b88e961461264827ae5478300f1d7cdd exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:01.174 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b88e961461264827ae5478300f1d7cdd __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:01.178 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 2357379a91f1430ab1bc86d6dfb5e876 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:01.235 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 2357379a91f1430ab1bc86d6dfb5e876 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:01.237 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:13:01.237 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:13:01.244 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 695ec59e634a490cbd68fbf4bf353779 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:01.272 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 695ec59e634a490cbd68fbf4bf353779 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:01.274 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:13:01.275 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:13:01.275 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.248s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:13:07.170 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 93499a4eea0c4d0dba36c70d12d6f633 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:07.189 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 93499a4eea0c4d0dba36c70d12d6f633 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:09.276 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:10.815 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:13.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:13.822 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:13:14.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:14.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: cb6b5580a77b497fa77b6ebae6fc9f88 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:14.839 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: cb6b5580a77b497fa77b6ebae6fc9f88 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:17.172 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 3428f68d9171450d90c1c220a19d31b4 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:17.190 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3428f68d9171450d90c1c220a19d31b4 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:17.819 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:17.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:13:17.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: d10490386097488bb6c53402318bed48 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:17.893 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d10490386097488bb6c53402318bed48 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:17.895 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-332d5e73-d056-4625-a1df-8eae908c89cf" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:13:17.895 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:13:17.896 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 8a5bbeb5924a4e88ada41d90d75cfa19 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:17.911 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8a5bbeb5924a4e88ada41d90d75cfa19 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:17.958 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=332d5e73-d056-4625-a1df-8eae908c89cf used request id req-e92fb9ef-0983-440f-bbdf-e3fe75e5d597 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:13:18.034 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-fded462e-65a0-4790-b20a-733701c7de32 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:13:18.393 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-5a623e85-c46e-4c55-8c10-b35387b6ff09 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:13:18.394 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:13:18.394 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:13:18.395 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 8b0c17d2061a40f3aa9f65eff87a160f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:18.410 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8b0c17d2061a40f3aa9f65eff87a160f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:18.411 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-332d5e73-d056-4625-a1df-8eae908c89cf" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:13:18.411 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:13:27.173 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: f0b8952785264613ae3abf0963b6357b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:27.192 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: f0b8952785264613ae3abf0963b6357b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:29.412 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:29.819 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:31.230 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received message with unique_id: cb5ad9d98b6a4dbab3a6f44509167333 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:269
>2018-06-22 22:13:31.238 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 861690113ee54277913cf62c7e635b97 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:31.363 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 861690113ee54277913cf62c7e635b97 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:31.365 183819 DEBUG nova.compute.manager [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:13:31.372 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: e5f600e882914b85a46576b4a4eb484b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:31.484 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e5f600e882914b85a46576b4a4eb484b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:31.486 183819 INFO nova.compute.manager [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] instance snapshotting
>2018-06-22 22:13:31.487 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: 306f0256a56043b88233a9b5da89dcfc NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:13:31.592 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727211.59, 377c527e-4693-4bf4-956b-741c82d6bc39 => Paused> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:13:31.592 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] VM Paused (Lifecycle Event)
>2018-06-22 22:13:31.594 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 7e83bdc1588c4fa1b382634b1a8fcac9 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:31.657 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7e83bdc1588c4fa1b382634b1a8fcac9 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:31.659 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:13:31.662 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Synchronizing instance power state after lifecycle event "Paused"; current vm_state: active, current task_state: image_snapshot, current DB power_state: 1, VM power_state: 3 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:13:31.665 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 18229fb0540d4f14970467b10349d014 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:31.731 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 18229fb0540d4f14970467b10349d014 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:31.732 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] During sync_power_state the instance has a pending task (image_snapshot). Skip.
>2018-06-22 22:13:32.054 183819 INFO nova.virt.libvirt.driver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Beginning cold snapshot process
>2018-06-22 22:13:32.057 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: ba98144215284fdd983adf860890c0a9 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:32.169 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ba98144215284fdd983adf860890c0a9 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:32.174 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: d5aa52b90bb94b0ca5437cfd662703b1 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:32.276 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d5aa52b90bb94b0ca5437cfd662703b1 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:32.356 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] creating snapshot(f2580ce178884fa69ae26d161e96e8f3) on rbd image(377c527e-4693-4bf4-956b-741c82d6bc39_disk) create_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:382
>2018-06-22 22:13:32.504 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] cloning vms/377c527e-4693-4bf4-956b-741c82d6bc39_disk@f2580ce178884fa69ae26d161e96e8f3 to images/3382b639-4668-47b0-9425-06e6e41964bc clone /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:231
>2018-06-22 22:13:32.593 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] flattening images/3382b639-4668-47b0-9425-06e6e41964bc flatten /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:281
>2018-06-22 22:13:37.175 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: c92c66f7cc4e42238e601eeb9b821570 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:37.202 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: c92c66f7cc4e42238e601eeb9b821570 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:37.519 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] removing snapshot(f2580ce178884fa69ae26d161e96e8f3) on rbd image(377c527e-4693-4bf4-956b-741c82d6bc39_disk) remove_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:410
>2018-06-22 22:13:38.336 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] creating snapshot(snap) on rbd image(3382b639-4668-47b0-9425-06e6e41964bc) create_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:382
>2018-06-22 22:13:39.665 183819 DEBUG nova.virt.libvirt.host [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Removed pending event for 377c527e-4693-4bf4-956b-741c82d6bc39 due to lifecycle event _event_emit_delayed /usr/lib/python2.7/site-packages/nova/virt/libvirt/host.py:303
>2018-06-22 22:13:39.666 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727219.66, 377c527e-4693-4bf4-956b-741c82d6bc39 => Started> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:13:39.666 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] VM Started (Lifecycle Event)
>2018-06-22 22:13:39.668 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 26e267f3d0f74190b7750d5fbef9fafc exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:39.727 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 26e267f3d0f74190b7750d5fbef9fafc __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:39.729 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:13:39.734 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Synchronizing instance power state after lifecycle event "Started"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:13:39.736 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 94968d25812f4a3984b16e33643ae93e exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:39.795 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 94968d25812f4a3984b16e33643ae93e __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:39.796 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:13:39.796 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727219.67, 377c527e-4693-4bf4-956b-741c82d6bc39 => Resumed> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:13:39.797 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] VM Resumed (Lifecycle Event)
>2018-06-22 22:13:39.798 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: b85bf905f9c140d9abba8bffd1eca3c6 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:39.924 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b85bf905f9c140d9abba8bffd1eca3c6 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:39.926 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:13:39.929 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Synchronizing instance power state after lifecycle event "Resumed"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:13:39.931 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 06636b4292204269b7b0856f2eef9fb5 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:39.987 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 06636b4292204269b7b0856f2eef9fb5 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:39.988 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:13:40.588 183819 INFO nova.virt.libvirt.driver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Snapshot image upload complete
>2018-06-22 22:13:40.591 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: b154c22d1f1a4067bc86428c60826895 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:40.695 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b154c22d1f1a4067bc86428c60826895 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:40.699 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-824a6019-331e-4468-8f26-2fd4b9c0d9c3 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: 3357ca4266a94159870841875813a4c8 NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:13:45.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:47.175 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: bedfd51f780e44339e07cd32861abe3b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:47.197 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: bedfd51f780e44339e07cd32861abe3b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:48.815 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._sync_scheduler_instance_info run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:48.817 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 3a54c69811a74d46a042c33a843faf5f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:48.857 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3a54c69811a74d46a042c33a843faf5f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:48.861 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CAST unique_id: 6a08ad388e69424f833dabb5165c397a FANOUT topic 'scheduler' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:557
>2018-06-22 22:13:51.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._cleanup_incomplete_migrations run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:13:51.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Cleaning up deleted instances with incomplete migration  _cleanup_incomplete_migrations /usr/lib/python2.7/site-packages/nova/compute/manager.py:6809
>2018-06-22 22:13:51.821 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 1ca899e3ac3746d1896de6f4dbadec94 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:51.837 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 1ca899e3ac3746d1896de6f4dbadec94 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:13:57.179 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: e2905c6fbbd348ffa50ea0ae136af35d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:13:57.199 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e2905c6fbbd348ffa50ea0ae136af35d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:01.838 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:01.839 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 96f9983a66ec48d9a562a60360b32cef exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:01.863 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 96f9983a66ec48d9a562a60360b32cef __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:01.868 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:14:01.929 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 9f9f4366aad94b778faaf71a1aed8a16 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:01.980 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 9f9f4366aad94b778faaf71a1aed8a16 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:01.984 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 11c2a9d16a1f4bf78fafff1cd9826942 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.001 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 11c2a9d16a1f4bf78fafff1cd9826942 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.006 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:14:02.007 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:14:02.072 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:14:02.073 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6759MB free_disk=96GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:14:02.074 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:14:02.077 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: e452bce6ac2947269e8f4789f899d475 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.108 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e452bce6ac2947269e8f4789f899d475 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.111 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:14:02.113 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: e525634f742e4beda0cbd3a98758ee86 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.189 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e525634f742e4beda0cbd3a98758ee86 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.196 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 7b4dd9cc189143579827531febafe37e exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.213 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7b4dd9cc189143579827531febafe37e __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.221 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 99400b735bb3448387d1dbd4991dac3d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.238 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 99400b735bb3448387d1dbd4991dac3d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.243 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: d612ea5f71a946d3b21b332e89204c3f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.296 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d612ea5f71a946d3b21b332e89204c3f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.298 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:14:02.298 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:14:02.307 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 63768abc0f5e4c26ae994c5d9735fae8 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:02.345 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 63768abc0f5e4c26ae994c5d9735fae8 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:02.347 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] No authentication information found for placement API. Placement is optional in Newton, but required in Ocata. Please enable the placement service before upgrading.
>2018-06-22 22:14:02.348 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:14:02.348 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:14:02.349 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.275s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:14:07.183 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 6c41a27000c34e7f83d478f8524237eb exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:07.202 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6c41a27000c34e7f83d478f8524237eb __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:10.332 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:10.815 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:13.823 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:13.824 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:14:16.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:16.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 84ed0629cace499d8df12d69511f67b2 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:16.846 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 84ed0629cace499d8df12d69511f67b2 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:17.185 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: a5b14bfd3cd14b8595c129778e676ae5 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:17.205 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a5b14bfd3cd14b8595c129778e676ae5 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:19.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:19.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:14:19.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5758
>2018-06-22 22:14:19.823 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 769c874464f74ffebcd7ced772e28ecc exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:19.858 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 769c874464f74ffebcd7ced772e28ecc __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:19.861 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:14:19.861 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:14:19.862 183819 DEBUG nova.objects.instance [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lazy-loading 'info_cache' on Instance uuid 377c527e-4693-4bf4-956b-741c82d6bc39 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1013
>2018-06-22 22:14:19.863 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 20dfd5ab6e794b7c8e7df58a5a5b4e0a exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:19.919 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 20dfd5ab6e794b7c8e7df58a5a5b4e0a __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:19.922 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 6df8f6cd9d334b72bcd016490a7937d0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:19.936 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6df8f6cd9d334b72bcd016490a7937d0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:19.989 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=377c527e-4693-4bf4-956b-741c82d6bc39 used request id req-ab93d184-2e26-472a-bef8-1cf0f54fc54f _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:14:20.070 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-05fbd13b-88cc-4d28-915e-9b231a8f4d66 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:14:20.151 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-f895dca8-b8fc-4cf8-8386-33d5060c6196 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:14:20.152 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:14:20.152 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:14:20.153 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 74ffbd5998f94e02a46bf98e9e1260ad exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:20.170 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 74ffbd5998f94e02a46bf98e9e1260ad __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:20.171 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:14:20.172 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:14:27.188 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 1c238233dba5406d83c6518cc539e98d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:27.214 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 1c238233dba5406d83c6518cc539e98d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:29.172 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:29.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:37.187 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 65ada48658964aaeb1c65f335ccafad7 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:37.206 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 65ada48658964aaeb1c65f335ccafad7 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:46.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:14:47.188 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: ceeab154f94a498485cccf7bf93c3c14 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:47.211 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ceeab154f94a498485cccf7bf93c3c14 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:54.529 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received message with unique_id: 17b7c399028a43428ae7890f5763f492 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:269
>2018-06-22 22:14:54.537 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 605007a90f2f4ab1b918660850410d27 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:54.637 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 605007a90f2f4ab1b918660850410d27 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:54.639 183819 DEBUG nova.compute.manager [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:14:54.647 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 68927eb98ce04057afdbc4f20b83124b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:54.747 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 68927eb98ce04057afdbc4f20b83124b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:54.749 183819 INFO nova.compute.manager [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] instance snapshotting
>2018-06-22 22:14:54.750 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: f64a6717f1f64e5a9da20b3ca555ad2d NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:14:54.884 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727294.88, 332d5e73-d056-4625-a1df-8eae908c89cf => Paused> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:14:54.884 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] VM Paused (Lifecycle Event)
>2018-06-22 22:14:54.885 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 5f442c09ea95428795e4173d84f912c0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:54.944 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 5f442c09ea95428795e4173d84f912c0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:54.946 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:14:54.949 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Synchronizing instance power state after lifecycle event "Paused"; current vm_state: active, current task_state: image_snapshot, current DB power_state: 1, VM power_state: 3 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:14:54.951 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 4a10962193024e739bc37285b4822c19 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:55.015 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 4a10962193024e739bc37285b4822c19 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:55.016 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] During sync_power_state the instance has a pending task (image_snapshot). Skip.
>2018-06-22 22:14:55.328 183819 INFO nova.virt.libvirt.driver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Beginning cold snapshot process
>2018-06-22 22:14:55.332 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: c95a22cd8093440b8b869ed3eed57559 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:55.443 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: c95a22cd8093440b8b869ed3eed57559 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:55.448 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: dd90b9026d6c4f14b7b6c6979da376de exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:55.615 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: dd90b9026d6c4f14b7b6c6979da376de __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:55.695 183819 DEBUG nova.virt.libvirt.imagebackend [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] No parent info for f7593a43-5674-4b26-933a-5aa74821dd21; asking the Image API where its store is _get_parent_pool /usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py:950
>2018-06-22 22:14:55.879 183819 DEBUG nova.virt.libvirt.imagebackend [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] Unable to get image f7593a43-5674-4b26-933a-5aa74821dd21; error: Image f7593a43-5674-4b26-933a-5aa74821dd21 could not be found. _get_parent_pool /usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py:956
>2018-06-22 22:14:55.880 183819 WARNING nova.virt.libvirt.driver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] Performing standard snapshot because direct snapshot failed: Cannot determine the parent storage pool for f7593a43-5674-4b26-933a-5aa74821dd21; cannot determine where to store images
>2018-06-22 22:14:55.883 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 8c1c690457c5409a97dee1cdbc2e7866 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:56.087 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8c1c690457c5409a97dee1cdbc2e7866 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:56.089 183819 DEBUG oslo_concurrency.processutils [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] Running cmd (subprocess): qemu-img convert -O raw rbd:vms/332d5e73-d056-4625-a1df-8eae908c89cf_disk:id=openstack:conf=/etc/ceph/ceph.conf /var/lib/nova/instances/snapshots/tmpnUlCAo/832fc5decbb44a3995548ec52a1e6914 -f raw execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:349
>2018-06-22 22:14:57.194 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: a83c6d31698b4805ae384af33e1e6716 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:57.206 183819 DEBUG oslo_concurrency.processutils [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CMD "qemu-img convert -O raw rbd:vms/332d5e73-d056-4625-a1df-8eae908c89cf_disk:id=openstack:conf=/etc/ceph/ceph.conf /var/lib/nova/instances/snapshots/tmpnUlCAo/832fc5decbb44a3995548ec52a1e6914 -f raw" returned: 0 in 1.116s execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:379
>2018-06-22 22:14:57.215 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a83c6d31698b4805ae384af33e1e6716 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:57.493 183819 DEBUG nova.virt.libvirt.host [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Removed pending event for 332d5e73-d056-4625-a1df-8eae908c89cf due to lifecycle event _event_emit_delayed /usr/lib/python2.7/site-packages/nova/virt/libvirt/host.py:303
>2018-06-22 22:14:57.493 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727297.49, 332d5e73-d056-4625-a1df-8eae908c89cf => Started> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:14:57.494 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] VM Started (Lifecycle Event)
>2018-06-22 22:14:57.495 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 8ecd38d23b424441b701f852ac44ff93 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:57.512 183819 INFO nova.virt.libvirt.driver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Snapshot extracted, beginning image upload
>2018-06-22 22:14:57.517 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: e8e0484b128d44b4899d94e1dccd37ca exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:57.557 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8ecd38d23b424441b701f852ac44ff93 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:57.560 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:14:57.565 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Synchronizing instance power state after lifecycle event "Started"; current vm_state: active, current task_state: image_pending_upload, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:14:57.568 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 79fc65a8086c4393ace2c371c14e2070 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:57.640 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 79fc65a8086c4393ace2c371c14e2070 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:57.641 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] During sync_power_state the instance has a pending task (image_pending_upload). Skip.
>2018-06-22 22:14:57.641 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727297.49, 332d5e73-d056-4625-a1df-8eae908c89cf => Resumed> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:14:57.642 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] VM Resumed (Lifecycle Event)
>2018-06-22 22:14:57.643 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 59f15f3975704717948d81795fa3085e exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:57.662 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e8e0484b128d44b4899d94e1dccd37ca __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:57.702 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 59f15f3975704717948d81795fa3085e __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:57.704 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:14:57.709 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Synchronizing instance power state after lifecycle event "Resumed"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:14:57.711 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 83d38e53877f49feb9b32f8aafa5d124 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:14:57.776 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 83d38e53877f49feb9b32f8aafa5d124 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:14:57.777 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:15:02.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:02.821 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 033beafad32c4bbda1b75f3fb696af28 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:02.851 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 033beafad32c4bbda1b75f3fb696af28 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:02.856 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:15:02.909 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 563e366f3bde4d31b8492769f2fe8886 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:02.965 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 563e366f3bde4d31b8492769f2fe8886 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:02.971 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 733de7e504f241179fcb273064a1eaa5 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:02.994 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 733de7e504f241179fcb273064a1eaa5 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:02.998 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:15:03.001 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:15:03.086 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:15:03.086 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6763MB free_disk=95GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:15:03.087 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:15:03.090 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: befc1ad16b584e78a53e0cf35fd0a0d0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:03.122 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: befc1ad16b584e78a53e0cf35fd0a0d0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:03.124 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:15:03.126 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 9a133900fc3548a2ab80f6abef1ffc2a exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:03.198 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 9a133900fc3548a2ab80f6abef1ffc2a __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:03.204 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 949cbb0a74574904819276de399d49e0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:03.223 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 949cbb0a74574904819276de399d49e0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:03.230 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 3b6ad9168478461da570fadd9f10117b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:03.252 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3b6ad9168478461da570fadd9f10117b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:03.256 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 638e6c74de8d4590864e935eed86e00c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:03.328 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 638e6c74de8d4590864e935eed86e00c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:03.329 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:15:03.329 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:15:03.336 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 54c11ff9e3164ed6a90059542e271688 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:03.374 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 54c11ff9e3164ed6a90059542e271688 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:03.376 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:15:03.376 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:15:03.376 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.290s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:15:07.198 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 17e4c0d8cf854444abe0a26279e69415 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:07.220 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 17e4c0d8cf854444abe0a26279e69415 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:11.377 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:11.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:15.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:15.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:15:16.827 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:16.829 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 36add6d93dec447b8f9b23d788c10f84 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:16.849 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 36add6d93dec447b8f9b23d788c10f84 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:17.203 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 83785e3d7f8c47ef827f2140dfef8b55 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:17.227 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 83785e3d7f8c47ef827f2140dfef8b55 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:20.819 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:20.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:15:20.821 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 7804e93fb8c649019703a98475a82c5a exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:20.909 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7804e93fb8c649019703a98475a82c5a __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:20.912 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-332d5e73-d056-4625-a1df-8eae908c89cf" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:15:20.912 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:15:20.913 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 1d4c93ff93a047bfa9d19e2e353cfe76 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:20.945 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 1d4c93ff93a047bfa9d19e2e353cfe76 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:21.055 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=332d5e73-d056-4625-a1df-8eae908c89cf used request id req-0c8f3ead-dd5b-41e0-97ad-6000d893b783 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:15:21.137 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-9e88c96c-a828-4185-bffd-c7aff5fecc1f _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:15:21.170 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-385ccf82-05a5-4a87-9f3d-a08b24474397 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:15:21.171 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:15:21.172 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:15:21.173 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 05ae16a7494a4143bbf2c39d454f1a24 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:21.188 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 05ae16a7494a4143bbf2c39d454f1a24 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:21.189 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-332d5e73-d056-4625-a1df-8eae908c89cf" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:15:21.189 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:15:27.201 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 0253342b354b4ea19a5f32ebcd57bece exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:27.223 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 0253342b354b4ea19a5f32ebcd57bece __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:29.191 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:29.734 183819 INFO nova.virt.libvirt.driver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 332d5e73-d056-4625-a1df-8eae908c89cf] Snapshot image upload complete
>2018-06-22 22:15:29.737 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: c930d384f8724e72bfe0d5a2abcf30e5 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:29.854 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: c930d384f8724e72bfe0d5a2abcf30e5 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:29.858 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-e7807498-c507-4cf6-a63b-a17a5be6b2cd c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: 648bc97a5f1d4bddad4e21d397e1585f NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:15:31.819 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:37.206 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: cc1ed16eac03420bb51beff2ee8cdb1f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:37.226 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: cc1ed16eac03420bb51beff2ee8cdb1f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:43.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_bandwidth_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:47.209 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 8f7c44d083504efa96f979f57e6d9b96 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:47.226 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8f7c44d083504efa96f979f57e6d9b96 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:47.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:48.815 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._sync_scheduler_instance_info run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:15:48.817 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 0a8b72c47f8941f98dd70bc171ab1edf exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:48.856 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 0a8b72c47f8941f98dd70bc171ab1edf __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:48.859 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CAST unique_id: 169765780ee74f0da2f08c3b73f9308e FANOUT topic 'scheduler' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:557
>2018-06-22 22:15:50.925 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received message with unique_id: dd42574850f04101ba201ab390d8c426 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:269
>2018-06-22 22:15:50.935 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 52c2d78d6c46405f958f07353835d08e exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:51.052 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 52c2d78d6c46405f958f07353835d08e __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:51.055 183819 DEBUG nova.compute.manager [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:15:51.063 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: a9b83db3b7b54ad6a3c94da4215cd6dc exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:51.175 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a9b83db3b7b54ad6a3c94da4215cd6dc __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:51.177 183819 INFO nova.compute.manager [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] instance snapshotting
>2018-06-22 22:15:51.178 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: 866f3eaa36bf4327b38ea1690bd388e8 NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:15:51.330 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727351.33, 377c527e-4693-4bf4-956b-741c82d6bc39 => Paused> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:15:51.331 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] VM Paused (Lifecycle Event)
>2018-06-22 22:15:51.332 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: af30e0ec66964b028d9892dd5d51d2d9 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:51.396 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: af30e0ec66964b028d9892dd5d51d2d9 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:51.398 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:15:51.404 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Synchronizing instance power state after lifecycle event "Paused"; current vm_state: active, current task_state: image_snapshot, current DB power_state: 1, VM power_state: 3 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:15:51.406 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: d2f040ef0ba946b398a0d300be123ec1 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:51.475 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d2f040ef0ba946b398a0d300be123ec1 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:51.477 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] During sync_power_state the instance has a pending task (image_snapshot). Skip.
>2018-06-22 22:15:51.780 183819 INFO nova.virt.libvirt.driver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Beginning cold snapshot process
>2018-06-22 22:15:51.784 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 18efc10079f848b59b62c7be6df289bb exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:51.925 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 18efc10079f848b59b62c7be6df289bb __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:51.930 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: 1b76373009d24b3b93ee3e1933b525b4 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:52.063 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 1b76373009d24b3b93ee3e1933b525b4 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:52.145 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] creating snapshot(e106c155949340c590d2b35d82d4710d) on rbd image(377c527e-4693-4bf4-956b-741c82d6bc39_disk) create_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:382
>2018-06-22 22:15:52.295 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] cloning vms/377c527e-4693-4bf4-956b-741c82d6bc39_disk@e106c155949340c590d2b35d82d4710d to images/e539fe93-091d-4d52-b77f-2aba1bcd5cbc clone /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:231
>2018-06-22 22:15:52.388 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] flattening images/e539fe93-091d-4d52-b77f-2aba1bcd5cbc flatten /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:281
>2018-06-22 22:15:57.209 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: db444a09145a4d0786de09ef353ef6ea exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:15:57.247 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: db444a09145a4d0786de09ef353ef6ea __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:15:59.835 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] removing snapshot(e106c155949340c590d2b35d82d4710d) on rbd image(377c527e-4693-4bf4-956b-741c82d6bc39_disk) remove_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:410
>2018-06-22 22:16:00.002 183819 DEBUG nova.virt.libvirt.storage.rbd_utils [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] creating snapshot(snap) on rbd image(e539fe93-091d-4d52-b77f-2aba1bcd5cbc) create_snap /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:382
>2018-06-22 22:16:01.351 183819 DEBUG nova.virt.libvirt.host [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Removed pending event for 377c527e-4693-4bf4-956b-741c82d6bc39 due to lifecycle event _event_emit_delayed /usr/lib/python2.7/site-packages/nova/virt/libvirt/host.py:303
>2018-06-22 22:16:01.353 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727361.35, 377c527e-4693-4bf4-956b-741c82d6bc39 => Started> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:16:01.353 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] VM Started (Lifecycle Event)
>2018-06-22 22:16:01.356 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 00b32856ebc04ce08d4a7c2998a7c5cd exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:01.418 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 00b32856ebc04ce08d4a7c2998a7c5cd __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:01.421 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:16:01.432 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Synchronizing instance power state after lifecycle event "Started"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:16:01.435 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 84d19a31134f47b79e04f97d89bd026c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:01.557 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 84d19a31134f47b79e04f97d89bd026c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:01.558 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:16:01.558 183819 DEBUG nova.virt.driver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] Emitting event <LifecycleEvent: 1529727361.35, 377c527e-4693-4bf4-956b-741c82d6bc39 => Resumed> emit_event /usr/lib/python2.7/site-packages/nova/virt/driver.py:1447
>2018-06-22 22:16:01.558 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] VM Resumed (Lifecycle Event)
>2018-06-22 22:16:01.560 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: 7e33e780c10b4c4a8183518b335d5b7f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:01.621 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7e33e780c10b4c4a8183518b335d5b7f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:01.623 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Checking state _get_power_state /usr/lib/python2.7/site-packages/nova/compute/manager.py:1174
>2018-06-22 22:16:01.627 183819 DEBUG nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Synchronizing instance power state after lifecycle event "Resumed"; current vm_state: active, current task_state: image_uploading, current DB power_state: 1, VM power_state: 1 handle_lifecycle_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:1092
>2018-06-22 22:16:01.629 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] CALL msg_id: d8e006ca9a6a463a919ce45fd22eba3f exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:01.694 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d8e006ca9a6a463a919ce45fd22eba3f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:01.695 183819 INFO nova.compute.manager [req-5b709da1-b3d4-45e6-989e-2d4540bb6be3 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] During sync_power_state the instance has a pending task (image_uploading). Skip.
>2018-06-22 22:16:02.548 183819 INFO nova.virt.libvirt.driver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Snapshot image upload complete
>2018-06-22 22:16:02.552 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CALL msg_id: a4d32b95d4c84048a3b926fc9e89087b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:02.668 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a4d32b95d4c84048a3b926fc9e89087b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:02.671 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-d7ae383d-e20f-43a7-8c23-2dbae87d06c6 c07b0e34c0314d9f9f8713640f08c8c4 373bd13ac03548698e6884af7c4b4805 - - -] CAST unique_id: b30371cc79e54e4f90f926a38728bcfc NOTIFY exchange 'nova' topic 'notifications.info' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:552
>2018-06-22 22:16:03.867 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:03.868 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: ca35eb7af8544dec861c6068d0356220 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:03.888 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ca35eb7af8544dec861c6068d0356220 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:03.892 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:16:03.947 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 99900a3b19d24cd8b59dbad1db7940e6 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.005 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 99900a3b19d24cd8b59dbad1db7940e6 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.009 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 7d92f069321c4ca0b49ce6a9d062bea2 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.029 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 7d92f069321c4ca0b49ce6a9d062bea2 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.033 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:16:04.036 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:16:04.095 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:16:04.095 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6757MB free_disk=87GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:16:04.096 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:16:04.099 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 86b1e0173fb04bad9b792a2c79cc4000 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.129 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 86b1e0173fb04bad9b792a2c79cc4000 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.131 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:16:04.132 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 962d3c255294487589dba07fc727e339 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.179 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 962d3c255294487589dba07fc727e339 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.186 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 866da425b4eb4df7809739f169cd2282 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.203 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 866da425b4eb4df7809739f169cd2282 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.206 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] No authentication information found for placement API. Placement is optional in Newton, but required in Ocata. Please enable the placement service before upgrading.
>2018-06-22 22:16:04.210 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 9c65097c3eaf4b898a34685c75c6d7cb exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.227 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 9c65097c3eaf4b898a34685c75c6d7cb __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.231 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: e8ecaacb20a14ca7b6754bf9e5e99a5b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.288 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: e8ecaacb20a14ca7b6754bf9e5e99a5b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.289 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:16:04.289 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:16:04.295 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: f58024131fbd41cdbf19296ab6b7c15c exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:04.324 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: f58024131fbd41cdbf19296ab6b7c15c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:04.326 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:16:04.326 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:16:04.327 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.231s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:16:07.210 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: d1c9f93c6ea048e097fa070bf7b5d80d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:07.230 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d1c9f93c6ea048e097fa070bf7b5d80d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:08.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._run_pending_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:08.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Cleaning up deleted instances _run_pending_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6774
>2018-06-22 22:16:08.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 757ab9da4509451ba2322bac55e23cfc exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:08.850 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 757ab9da4509451ba2322bac55e23cfc __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:08.851 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] There are 0 instances to clean _run_pending_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6783
>2018-06-22 22:16:11.852 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:13.816 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:15.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:15.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:16:17.186 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._sync_power_states run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:17.188 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 027b03c1fb0a492bb0d81d5fc869c210 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:17.212 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: b9d59ea5990d49a2b2355aa2df39e642 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:17.223 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 027b03c1fb0a492bb0d81d5fc869c210 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:17.228 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Triggering sync for uuid 377c527e-4693-4bf4-956b-741c82d6bc39 _sync_power_states /usr/lib/python2.7/site-packages/nova/compute/manager.py:6230
>2018-06-22 22:16:17.228 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Triggering sync for uuid 332d5e73-d056-4625-a1df-8eae908c89cf _sync_power_states /usr/lib/python2.7/site-packages/nova/compute/manager.py:6230
>2018-06-22 22:16:17.229 183819 DEBUG oslo_concurrency.lockutils [-] Lock "377c527e-4693-4bf4-956b-741c82d6bc39" acquired by "nova.compute.manager.query_driver_power_state_and_sync" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:16:17.229 183819 DEBUG oslo_concurrency.lockutils [-] Lock "332d5e73-d056-4625-a1df-8eae908c89cf" acquired by "nova.compute.manager.query_driver_power_state_and_sync" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:16:17.232 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b9d59ea5990d49a2b2355aa2df39e642 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:17.237 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: aa19528422944e95b7793cf6795e7e9b exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:17.240 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 55a10ca65e9a446f95ffa75ecbaa3251 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:17.296 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 55a10ca65e9a446f95ffa75ecbaa3251 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:17.297 183819 DEBUG oslo_concurrency.lockutils [-] Lock "332d5e73-d056-4625-a1df-8eae908c89cf" released by "nova.compute.manager.query_driver_power_state_and_sync" :: held 0.068s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:16:17.298 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: aa19528422944e95b7793cf6795e7e9b __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:17.299 183819 DEBUG oslo_concurrency.lockutils [-] Lock "377c527e-4693-4bf4-956b-741c82d6bc39" released by "nova.compute.manager.query_driver_power_state_and_sync" :: held 0.070s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:16:18.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:18.821 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 5aaef9d0b0c84509abff7f4a3700b3c4 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:18.837 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 5aaef9d0b0c84509abff7f4a3700b3c4 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:22.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:22.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5754
>2018-06-22 22:16:22.821 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5758
>2018-06-22 22:16:22.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 6ecc3b60227747fb956c928a11d617f9 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:22.858 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6ecc3b60227747fb956c928a11d617f9 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:22.860 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Acquired semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
>2018-06-22 22:16:22.861 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1293
>2018-06-22 22:16:22.861 183819 DEBUG nova.objects.instance [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lazy-loading 'info_cache' on Instance uuid 377c527e-4693-4bf4-956b-741c82d6bc39 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1013
>2018-06-22 22:16:22.862 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 3a350367b4ca4c9883aa0de88d5eddc2 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:22.925 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3a350367b4ca4c9883aa0de88d5eddc2 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:22.928 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 6a3b0682b8cc49ab89039cc314e75416 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:22.942 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6a3b0682b8cc49ab89039cc314e75416 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:23.073 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/ports.json?tenant_id=373bd13ac03548698e6884af7c4b4805&device_id=377c527e-4693-4bf4-956b-741c82d6bc39 used request id req-7792df16-db2d-4015-bb5d-da1e6cc19858 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:16:23.116 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?tenant_id=373bd13ac03548698e6884af7c4b4805&shared=False used request id req-111a6e3b-ad02-4070-b6c8-a1f32c1df778 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:16:23.201 183819 DEBUG neutronclient.v2_0.client [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] GET call to neutron for http://172.17.1.14:9696/v2.0/networks.json?shared=True used request id req-efa8f8cf-284a-4782-bd2c-5ef3d9b7a232 _append_request_id /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:128
>2018-06-22 22:16:23.202 183819 DEBUG nova.network.neutronv2.api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2187
>2018-06-22 22:16:23.202 183819 DEBUG nova.network.base_api [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43
>2018-06-22 22:16:23.203 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: eeb8238c3cba4d2b94b5548da89577be exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:23.218 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: eeb8238c3cba4d2b94b5548da89577be __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:23.219 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Releasing semaphore "refresh_cache-377c527e-4693-4bf4-956b-741c82d6bc39" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
>2018-06-22 22:16:23.220 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] [instance: 377c527e-4693-4bf4-956b-741c82d6bc39] Updated the network info_cache for instance _heal_instance_info_cache /usr/lib/python2.7/site-packages/nova/compute/manager.py:5816
>2018-06-22 22:16:27.215 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 9058cf7403f64b279b19d14fb76e35d0 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:27.236 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 9058cf7403f64b279b19d14fb76e35d0 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:29.220 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:33.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:37.219 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 453e85e5dec0498a8b096088518c5f2a exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:37.237 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 453e85e5dec0498a8b096088518c5f2a __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:47.220 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 18a5465d22124fbdb804aa293a9b7038 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:47.250 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 18a5465d22124fbdb804aa293a9b7038 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:16:47.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:16:57.222 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 360bd172c5544f36a64d88e059565717 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:16:57.243 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 360bd172c5544f36a64d88e059565717 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:03.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:17:03.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 2d4dc9b4ebbf459f9a8f3de80b91f819 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:03.844 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 2d4dc9b4ebbf459f9a8f3de80b91f819 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:03.849 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Auditing locally available compute resources for node compute-0.localdomain
>2018-06-22 22:17:03.893 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: ef44c9bd67a1405f9706a2dadfe07167 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:03.936 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ef44c9bd67a1405f9706a2dadfe07167 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:03.940 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 8c7c1f075b084ca399079990e6c29f01 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:03.955 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 8c7c1f075b084ca399079990e6c29f01 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:03.958 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-0000004f as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:17:03.959 183819 DEBUG nova.virt.libvirt.driver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] skipping disk for instance-00000046 as it does not have a path _get_instance_disk_info /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:7047
>2018-06-22 22:17:04.012 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor: free VCPUs: 2 _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:623
>2018-06-22 22:17:04.013 183819 DEBUG nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Hypervisor/Node resource view: name=compute-0.localdomain free_ram=6755MB free_disk=87GB free_vcpus=2 pci_devices=[{"dev_id": "pci_0000_00_07_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:07.0"}, {"dev_id": "pci_0000_00_06_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:06.7"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_06_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:06.1"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_08_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:08.0"}, {"dev_id": "pci_0000_00_09_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:09.0"}, {"dev_id": "pci_0000_00_0a_0", "product_id": "1005", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1005", "address": "0000:00:0a.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:06.0"}, {"dev_id": "pci_0000_00_06_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:06.2"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_02_0", "product_id": "00b8", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1013", "label": "label_1013_00b8", "address": "0000:00:02.0"}] _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
>2018-06-22 22:17:04.013 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
>2018-06-22 22:17:04.016 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 6c9799e263db4e6f8dab9eadc1ba0566 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:04.044 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 6c9799e263db4e6f8dab9eadc1ba0566 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:04.046 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:17:04.048 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: abcb5c1e96a04e0eb5793c23cbb06f77 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:04.094 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: abcb5c1e96a04e0eb5793c23cbb06f77 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:04.100 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: b794856468144fd29c0347734f3c0491 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:04.117 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b794856468144fd29c0347734f3c0491 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:04.123 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 0adc180a05644bbc96b97448c750696d exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:04.139 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 0adc180a05644bbc96b97448c750696d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:04.143 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: f72a0635dfd944209d994b40083bb527 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:04.186 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: f72a0635dfd944209d994b40083bb527 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:04.187 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Total usable vcpus: 4, total allocated vcpus: 2
>2018-06-22 22:17:04.188 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Final resource view: name=compute-0.localdomain phys_ram=8191MB used_ram=3072MB phys_disk=104GB used_disk=4GB total_vcpus=4 used_vcpus=2 pci_stats=[]
>2018-06-22 22:17:04.194 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 3b66e43f149f446e9035d3fe35652101 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:04.219 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3b66e43f149f446e9035d3fe35652101 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:04.221 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] No authentication information found for placement API. Placement is optional in Newton, but required in Ocata. Please enable the placement service before upgrading.
>2018-06-22 22:17:04.221 183819 WARNING nova.scheduler.client.report [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Unable to refresh my resource provider record
>2018-06-22 22:17:04.222 183819 INFO nova.compute.resource_tracker [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Compute_service record updated for compute-0.localdomain:compute-0.localdomain
>2018-06-22 22:17:04.222 183819 DEBUG oslo_concurrency.lockutils [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.209s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
>2018-06-22 22:17:07.226 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: 452a2dc5229d43fa8fe725149b4a7ab3 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:07.249 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 452a2dc5229d43fa8fe725149b4a7ab3 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:13.817 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:17:13.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:17:15.820 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:17:15.820 183819 DEBUG nova.compute.manager [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:6426
>2018-06-22 22:17:17.222 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: a7b0f7774bed4e43910ad0c7fdbfc494 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:17.240 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a7b0f7774bed4e43910ad0c7fdbfc494 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416
>2018-06-22 22:17:18.821 183819 DEBUG oslo_service.periodic_task [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
>2018-06-22 22:17:18.822 183819 DEBUG oslo_messaging._drivers.amqpdriver [req-c50f32d5-fb6f-4678-bbfb-528a4db5d850 - - - - -] CALL msg_id: 13728f4b7d38406a88410962c5079b91 exchange 'nova' topic 'conductor' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:568
>2018-06-22 22:17:18.836 183819 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 13728f4b7d38406a88410962c5079b91 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:416

Actions: View

Attachments on bug 1594454: 1453895 | 1453896