Revision history [back]

click to hide/show revision 1
initial version

deleted instance running on compute

Hi All

i am using openstack Juno controller/compute 2014.2.2 on ubuntu 14.04

recently i have deleted 2 instances using the Dashboard successfully, however the instances still running active on the compute

when searching the nova-compute.log i have seen that the process stop from logging few minutes before the deletion took place and also service nova-compute status was running

further on as i understand there is a periodic task '_cleanup_running_deleted_instances' that should find such instances and by default (reap) will delete those instances and that it is configure to run every 1800 sec by default.

however the instances remain as active in the compute

further on after restart the instances were not deleted and instead they change to shutoff

from watching the log i noticed that it detected the discrepancy but again they been only shutdown and not deleted (udefine)

my question : what is needed to be configured in order to make sure deleted instances are confirmed as deleted during run-time and start of nova-compute ?

bellow log od the nova-compute.log only from the reboot time ,not before

2015-06-04 17:51:08.488 2625 DEBUG nova.openstack.common.service [-] running_deleted_instance_action = reap log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:1992
2015-06-04 17:51:08.488 2625 DEBUG nova.openstack.common.service [-] running_deleted_instance_poll_interval = 1800 log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:1992
2015-06-04 17:51:08.489 2625 DEBUG nova.openstack.common.service [-] running_deleted_instance_timeout = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:1992
2


2015-06-04 17:51:08.966 2625 DEBUG nova.openstack.common.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:2002
2015-06-04 17:51:08.970 2625 AUDIT nova.service [-] Starting compute node (version 2014.2.1)
2015-06-04 17:51:08.973 2625 DEBUG nova.virt.libvirt.driver [-] Connecting to libvirt: qemu:///system _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:724
2015-06-04 17:51:10.974 2625 DEBUG nova.virt.libvirt.driver [-] Registering for lifecycle events <nova.virt.libvirt.driver.LibvirtDriver object at 0x7f091253a8d0> _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:741
2015-06-04 17:51:10.976 2625 DEBUG nova.virt.libvirt.driver [-] Registering for connection events: <nova.virt.libvirt.driver.LibvirtDriver object at 0x7f091253a8d0> _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:752
2015-06-04 17:51:10.990 2625 DEBUG nova.virt.libvirt.config [-] Generated XML ('<cpu>\n  <arch>x86_64</arch>\n  <model>Haswell</model>\n  <vendor>Intel</vendor>\n  <topology sockets="1" cores="4" threads="2"/>\n  <feature name="abm"/>\n  <feature name="acpi"/>\n  <feature name="ds"/>\n  <feature name="ds_cpl"/>\n  <feature name="dtes64"/>\n  <feature name="est"/>\n  <feature name="f16c"/>\n  <feature name="ht"/>\n  <feature name="monitor"/>\n  <feature name="osxsave"/>\n  <feature name="pbe"/>\n  <feature name="pdcm"/>\n  <feature name="pdpe1gb"/>\n  <feature name="rdrand"/>\n  <feature name="smx"/>\n  <feature name="ss"/>\n  <feature name="tm"/>\n  <feature name="tm2"/>\n  <feature name="vme"/>\n  <feature name="vmx"/>\n  <feature name="xtpr"/>\n</cpu>\n',)  to_xml /usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py:82
2015-06-04 17:51:10.995 2625 DEBUG nova.virt.libvirt.driver [-] Starting native event thread _init_events /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:663
2015-06-04 17:51:10.995 2625 DEBUG nova.virt.libvirt.driver [-] Starting green dispatch thread _init_events /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:668
2015-06-04 17:51:11.056 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:51:11.190 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:51:11.191 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:51:11.326 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7492 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:51:11.326 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:51:11.327 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:51:11.330 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:51:11.330 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:51:11.334 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:51:11.334 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:51:11.478 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:51:11.479 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:51:11.479 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:51:11.479 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:51:11.544 2625 INFO nova.scheduler.client.report [-] Compute_service record updated for ('0020d2e02c67', '0020d2e02c67')
2015-06-04 17:51:11.545 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:51:11.545 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:51:11.546 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:51:11.579 2625 DEBUG nova.service [-] Creating RPC server for service compute start /usr/lib/python2.7/dist-packages/nova/service.py:186
2015-06-04 17:51:11.581 2625 INFO oslo.messaging._drivers.impl_rabbit [-] Connecting to AMQP server on controller:5672
2015-06-04 17:51:11.606 2625 INFO oslo.messaging._drivers.impl_rabbit [-] Connected to AMQP server on controller:5672
2015-06-04 17:51:11.618 2625 DEBUG nova.service [-] Join ServiceGroup membership for this service compute start /usr/lib/python2.7/dist-packages/nova/service.py:204
2015-06-04 17:51:11.618 2625 DEBUG nova.servicegroup.api [-] Join new ServiceGroup member 0020d2e02c67 to the compute group, service = <nova.service.Service object at 0x7f0912cbae50> join /usr/lib/python2.7/dist-packages/nova/servicegroup/api.py:109
2015-06-04 17:51:11.619 2625 DEBUG nova.servicegroup.drivers.db [-] DB_Driver: join new ServiceGroup member 0020d2e02c67 to the compute group, service = <nova.service.Service object at 0x7f0912cbae50> join /usr/lib/python2.7/dist-packages/nova/servicegroup/drivers/db.py:46
2015-06-04 17:51:17.620 2625 DEBUG nova.openstack.common.periodic_task [req-235cbc37-94c0-4b4b-9cb1-e59af8cd88ab None] Running periodic task ComputeManager._sync_power_states run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:51:17.662 2625 WARNING nova.compute.manager [req-235cbc37-94c0-4b4b-9cb1-e59af8cd88ab None] While synchronizing instance power states, found 0 instances in the database and 2 instances on the hypervisor.
2015-06-04 17:51:17.663 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 49.31 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:52:06.975 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:06.977 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:52:06.981 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:06.983 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:52:06.984 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:52:07.054 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7441 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:52:07.054 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:52:07.055 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:52:07.055 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:52:07.055 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:52:07.056 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:52:07.056 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:52:07.123 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:52:07.124 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:52:07.125 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:52:07.126 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:52:07.126 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:52:07.127 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:52:07.128 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:52:07.167 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.168 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.169 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.170 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:52:07.171 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.172 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.173 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.174 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:52:07.174 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:52:07.190 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:52:07.191 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 60.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:53:07.192 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.193 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.194 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.194 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:53:07.195 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.196 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:53:07.196 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:53:07.248 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:53:07.249 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.78 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:53:08.030 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.031 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.031 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.032 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.033 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.95 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:53:08.985 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.986 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:53:08.986 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:53:09.055 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7440 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:53:09.056 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:53:09.056 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:53:09.057 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:53:09.057 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:53:09.057 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:53:09.058 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:53:09.197 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:53:09.198 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:53:09.199 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:53:09.199 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:53:09.200 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:53:09.201 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:53:09.201 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:53:09.250 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 57.73 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:06.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:06.984 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:54:06.985 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 1.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:07.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:07.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:07.983 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:54:07.984 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:54:08.016 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:54:08.017 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 1.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:09.017 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.018 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:54:09.019 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:54:09.089 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7436 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:54:09.089 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:54:09.090 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:54:09.090 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:54:09.091 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:54:09.091 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:54:09.091 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:54:09.141 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:54:09.142 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:54:09.142 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:54:09.143 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:54:09.144 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:54:09.144 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:54:09.145 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:54:09.184 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.79 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:09.976 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.977 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:09.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.984 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 57.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:06.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:06.983 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:55:06.984 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 2.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:08.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:08.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:08.984 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:08.984 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:55:08.985 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:55:09.026 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:55:09.027 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 1.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:10.025 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:10.026 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:10.027 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.96 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:10.984 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:10.985 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:55:10.985 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:55:11.058 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7436 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:55:11.058 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:55:11.058 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:55:11.059 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:55:11.059 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:55:11.060 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:55:11.060 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:55:11.144 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:55:11.145 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:55:11.146 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:55:11.147 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:55:11.148 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:55:11.148 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:55:11.149 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:55:11.193 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:11.195 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.78 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:11.976 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:11.976 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 55.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:56:06.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:56:06.983 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:56:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._run_pending_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:56:06.984 2625 DEBUG nova.compute.manager [-] Cleaning up deleted instances _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6232
2015-06-04 17:56:07.055 2625 DEBUG nova.compute.manager [-] There are 2 instances to clean _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6241
2015-06-04 17:56:07.056 2625 DEBUG nova.compute.manager [-] [instance: 51a053b5-d6d6-4d96-8c4c-4d09897db3ed] Instance has had 0 of 5 cleanup attempts _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6249
2015-06-04 17:56:07.062 2625 DEBUG nova.openstack.common.processutils [-] Running cmd (subprocess): mv /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed_del execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:161
2015-06-04 17:56:07.085 2625 DEBUG nova.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:195
2015-06-04 17:56:07.086 2625 INFO nova.virt.libvirt.driver [-] [instance: 51a053b5-d6d6-4d96-8c4c-4d09897db3ed] Deleting instance files /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed_del
2015-06-04 17:56:07.088 2625 INFO nova.virt.libvirt.driver [-] [instance: 51a053b5-d6d6-4d96-8c4c-4d09897db3ed] Deletion of /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed_del complete
2015-06-04 17:56:07.174 2625 DEBUG nova.compute.manager [-] [instance: c631457e-5663-48e9-8729-e0ab28a815eb] Instance has had 0 of 5 cleanup attempts _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6249
2015-06-04 17:56:07.175 2625 DEBUG nova.openstack.common.processutils [-] Running cmd (subprocess): mv /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb_del execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:161
2015-06-04 17:56:07.199 2625 DEBUG nova.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:195
2015-06-04 17:56:07.201 2625 INFO nova.virt.libvirt.driver [-] [instance: c631457e-5663-48e9-8729-e0ab28a815eb] Deleting instance files /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb_del
2015-06-04 17:56:07.202 2625 INFO nova.virt.libvirt.driver [-] [instance: c631457e-5663-48e9-8729-e0ab28a815eb] Deletion of /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb_del complete
2015-06-04 17:56:07.290 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 2.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132

deleted instance running on compute

Hi All

i am using openstack Juno controller/compute 2014.2.2 on ubuntu 14.04

recently i have deleted 2 instances using the Dashboard successfully, however the instances still running active on the compute

when searching the nova-compute.log i have seen that the process stop from logging few minutes before the deletion took place and also service nova-compute status was running

further on as i understand there is a periodic task '_cleanup_running_deleted_instances' that should find such instances and by default (reap) will delete those instances and that it is configure to run every 1800 sec by default.

however the instances remain as active in the compute

in the controller the nova-compute service were UP

further on after restart the instances were not deleted and instead they change to shutoff

from watching the log i noticed that it detected the discrepancy but again they been only shutdown and not deleted (udefine)

my question : what is needed to be configured in order to make sure deleted instances are confirmed as deleted during run-time and start of nova-compute ?

bellow log od the nova-compute.log only from the reboot time ,not before

2015-06-04 17:51:08.488 2625 DEBUG nova.openstack.common.service [-] running_deleted_instance_action = reap log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:1992
2015-06-04 17:51:08.488 2625 DEBUG nova.openstack.common.service [-] running_deleted_instance_poll_interval = 1800 log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:1992
2015-06-04 17:51:08.489 2625 DEBUG nova.openstack.common.service [-] running_deleted_instance_timeout = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:1992
2


2015-06-04 17:51:08.966 2625 DEBUG nova.openstack.common.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo/config/cfg.py:2002
2015-06-04 17:51:08.970 2625 AUDIT nova.service [-] Starting compute node (version 2014.2.1)
2015-06-04 17:51:08.973 2625 DEBUG nova.virt.libvirt.driver [-] Connecting to libvirt: qemu:///system _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:724
2015-06-04 17:51:10.974 2625 DEBUG nova.virt.libvirt.driver [-] Registering for lifecycle events <nova.virt.libvirt.driver.LibvirtDriver object at 0x7f091253a8d0> _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:741
2015-06-04 17:51:10.976 2625 DEBUG nova.virt.libvirt.driver [-] Registering for connection events: <nova.virt.libvirt.driver.LibvirtDriver object at 0x7f091253a8d0> _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:752
2015-06-04 17:51:10.990 2625 DEBUG nova.virt.libvirt.config [-] Generated XML ('<cpu>\n  <arch>x86_64</arch>\n  <model>Haswell</model>\n  <vendor>Intel</vendor>\n  <topology sockets="1" cores="4" threads="2"/>\n  <feature name="abm"/>\n  <feature name="acpi"/>\n  <feature name="ds"/>\n  <feature name="ds_cpl"/>\n  <feature name="dtes64"/>\n  <feature name="est"/>\n  <feature name="f16c"/>\n  <feature name="ht"/>\n  <feature name="monitor"/>\n  <feature name="osxsave"/>\n  <feature name="pbe"/>\n  <feature name="pdcm"/>\n  <feature name="pdpe1gb"/>\n  <feature name="rdrand"/>\n  <feature name="smx"/>\n  <feature name="ss"/>\n  <feature name="tm"/>\n  <feature name="tm2"/>\n  <feature name="vme"/>\n  <feature name="vmx"/>\n  <feature name="xtpr"/>\n</cpu>\n',)  to_xml /usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py:82
2015-06-04 17:51:10.995 2625 DEBUG nova.virt.libvirt.driver [-] Starting native event thread _init_events /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:663
2015-06-04 17:51:10.995 2625 DEBUG nova.virt.libvirt.driver [-] Starting green dispatch thread _init_events /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:668
2015-06-04 17:51:11.056 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:51:11.190 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:51:11.191 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:51:11.326 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7492 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:51:11.326 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:51:11.327 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:51:11.330 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:51:11.330 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:51:11.334 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:51:11.334 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:51:11.478 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:51:11.479 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:51:11.479 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:51:11.479 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:51:11.544 2625 INFO nova.scheduler.client.report [-] Compute_service record updated for ('0020d2e02c67', '0020d2e02c67')
2015-06-04 17:51:11.545 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:51:11.545 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:51:11.546 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:51:11.579 2625 DEBUG nova.service [-] Creating RPC server for service compute start /usr/lib/python2.7/dist-packages/nova/service.py:186
2015-06-04 17:51:11.581 2625 INFO oslo.messaging._drivers.impl_rabbit [-] Connecting to AMQP server on controller:5672
2015-06-04 17:51:11.606 2625 INFO oslo.messaging._drivers.impl_rabbit [-] Connected to AMQP server on controller:5672
2015-06-04 17:51:11.618 2625 DEBUG nova.service [-] Join ServiceGroup membership for this service compute start /usr/lib/python2.7/dist-packages/nova/service.py:204
2015-06-04 17:51:11.618 2625 DEBUG nova.servicegroup.api [-] Join new ServiceGroup member 0020d2e02c67 to the compute group, service = <nova.service.Service object at 0x7f0912cbae50> join /usr/lib/python2.7/dist-packages/nova/servicegroup/api.py:109
2015-06-04 17:51:11.619 2625 DEBUG nova.servicegroup.drivers.db [-] DB_Driver: join new ServiceGroup member 0020d2e02c67 to the compute group, service = <nova.service.Service object at 0x7f0912cbae50> join /usr/lib/python2.7/dist-packages/nova/servicegroup/drivers/db.py:46
2015-06-04 17:51:17.620 2625 DEBUG nova.openstack.common.periodic_task [req-235cbc37-94c0-4b4b-9cb1-e59af8cd88ab None] Running periodic task ComputeManager._sync_power_states run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:51:17.662 2625 WARNING nova.compute.manager [req-235cbc37-94c0-4b4b-9cb1-e59af8cd88ab None] While synchronizing instance power states, found 0 instances in the database and 2 instances on the hypervisor.
2015-06-04 17:51:17.663 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 49.31 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:52:06.975 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:06.977 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:52:06.981 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:06.983 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:52:06.984 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:52:07.054 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7441 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:52:07.054 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:52:07.055 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:52:07.055 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:52:07.055 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:52:07.056 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:52:07.056 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:52:07.123 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:52:07.124 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:52:07.125 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:52:07.126 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:52:07.126 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:52:07.127 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:52:07.128 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:52:07.167 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.168 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.169 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.170 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:52:07.171 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.172 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.173 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:52:07.174 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:52:07.174 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:52:07.190 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:52:07.191 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 60.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:53:07.192 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.193 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.194 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.194 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:53:07.195 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:07.196 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:53:07.196 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:53:07.248 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:53:07.249 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.78 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:53:08.030 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.031 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.031 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.032 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.033 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.95 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:53:08.985 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:53:08.986 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:53:08.986 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:53:09.055 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7440 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:53:09.056 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:53:09.056 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:53:09.057 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:53:09.057 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:53:09.057 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:53:09.058 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:53:09.197 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:53:09.198 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:53:09.199 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:53:09.199 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:53:09.200 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:53:09.201 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:53:09.201 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:53:09.250 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 57.73 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:06.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:06.984 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:54:06.985 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 1.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:07.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:07.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:07.983 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:54:07.984 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:54:08.016 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:54:08.017 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 1.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:09.017 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.018 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:54:09.019 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:54:09.089 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7436 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:54:09.089 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:54:09.090 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:54:09.090 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:54:09.091 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:54:09.091 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:54:09.091 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:54:09.141 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:54:09.142 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:54:09.142 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:54:09.143 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:54:09.144 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:54:09.144 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:54:09.145 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:54:09.184 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.79 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:09.976 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.977 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:54:09.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:54:09.984 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 57.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:06.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:06.983 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:55:06.984 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 2.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:08.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:08.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:08.984 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:08.984 2625 DEBUG nova.compute.manager [-] Starting heal instance info cache _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5292
2015-06-04 17:55:08.985 2625 DEBUG nova.compute.manager [-] Rebuilding the list of instances to heal _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5296
2015-06-04 17:55:09.026 2625 DEBUG nova.compute.manager [-] Didn't find any instances for network info cache update. _heal_instance_info_cache /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5358
2015-06-04 17:55:09.027 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 1.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:10.025 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:10.026 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:10.027 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.96 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:10.984 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:10.985 2625 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-06-04 17:55:10.985 2625 DEBUG nova.virt.libvirt.driver [-] Updating host stats update_status /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:6388
2015-06-04 17:55:11.058 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 7436 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:454
2015-06-04 17:55:11.058 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 49 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:455
2015-06-04 17:55:11.058 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: free VCPUs: 8 _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:460
2015-06-04 17:55:11.059 2625 DEBUG nova.compute.resource_tracker [-] Hypervisor: assignable PCI devices: [] _report_hypervisor_resource_view /usr/lib/python2.7/dist-packages/nova/compute/resource_tracker.py:467
2015-06-04 17:55:11.059 2625 DEBUG nova.openstack.common.lockutils [-] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-06-04 17:55:11.060 2625 DEBUG nova.openstack.common.lockutils [-] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-06-04 17:55:11.060 2625 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-06-04 17:55:11.144 2625 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 7893, total allocated virtual ram (MB): 512
2015-06-04 17:55:11.145 2625 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 50
2015-06-04 17:55:11.146 2625 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-06-04 17:55:11.147 2625 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-06-04 17:55:11.148 2625 INFO nova.compute.resource_tracker [-] Compute_service record updated for 0020d2e02c67:0020d2e02c67
2015-06-04 17:55:11.148 2625 DEBUG nova.openstack.common.lockutils [-] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-06-04 17:55:11.149 2625 DEBUG nova.openstack.common.lockutils [-] Semaphore / lock released "_update_available_resource" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-06-04 17:55:11.193 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:11.195 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 0.78 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:55:11.976 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:55:11.976 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 55.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132
2015-06-04 17:56:06.982 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:56:06.983 2625 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:5941
2015-06-04 17:56:06.983 2625 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._run_pending_deletes run_periodic_tasks /usr/lib/python2.7/dist-packages/nova/openstack/common/periodic_task.py:193
2015-06-04 17:56:06.984 2625 DEBUG nova.compute.manager [-] Cleaning up deleted instances _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6232
2015-06-04 17:56:07.055 2625 DEBUG nova.compute.manager [-] There are 2 instances to clean _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6241
2015-06-04 17:56:07.056 2625 DEBUG nova.compute.manager [-] [instance: 51a053b5-d6d6-4d96-8c4c-4d09897db3ed] Instance has had 0 of 5 cleanup attempts _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6249
2015-06-04 17:56:07.062 2625 DEBUG nova.openstack.common.processutils [-] Running cmd (subprocess): mv /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed_del execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:161
2015-06-04 17:56:07.085 2625 DEBUG nova.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:195
2015-06-04 17:56:07.086 2625 INFO nova.virt.libvirt.driver [-] [instance: 51a053b5-d6d6-4d96-8c4c-4d09897db3ed] Deleting instance files /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed_del
2015-06-04 17:56:07.088 2625 INFO nova.virt.libvirt.driver [-] [instance: 51a053b5-d6d6-4d96-8c4c-4d09897db3ed] Deletion of /var/lib/nova/instances/51a053b5-d6d6-4d96-8c4c-4d09897db3ed_del complete
2015-06-04 17:56:07.174 2625 DEBUG nova.compute.manager [-] [instance: c631457e-5663-48e9-8729-e0ab28a815eb] Instance has had 0 of 5 cleanup attempts _run_pending_deletes /usr/lib/python2.7/dist-packages/nova/compute/manager.py:6249
2015-06-04 17:56:07.175 2625 DEBUG nova.openstack.common.processutils [-] Running cmd (subprocess): mv /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb_del execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:161
2015-06-04 17:56:07.199 2625 DEBUG nova.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:195
2015-06-04 17:56:07.201 2625 INFO nova.virt.libvirt.driver [-] [instance: c631457e-5663-48e9-8729-e0ab28a815eb] Deleting instance files /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb_del
2015-06-04 17:56:07.202 2625 INFO nova.virt.libvirt.driver [-] [instance: c631457e-5663-48e9-8729-e0ab28a815eb] Deletion of /var/lib/nova/instances/c631457e-5663-48e9-8729-e0ab28a815eb_del complete
2015-06-04 17:56:07.290 2625 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x7f0912cbae50>> sleeping for 2.00 seconds _inner /usr/lib/python2.7/dist-packages/nova/openstack/common/loopingcall.py:132