xenapi plugin exception when launching an instance

Asked by arturo lorenzo

Hi, I am getting a timeout when launching an instance. I am running XCP version 1.1 then launching a VM with ubuntu 10.04 64bit where I have installed nova core:trunk on it.
The instance is running:
INSTANCE i-00000002 ami-00000003 10.0.0.2 10.0.0.2 running None (openstack, ubuntu-xcp-os) 0 m1.small 2011-09-23T14:26:10Z nova aki-00000002 ari-00000001
but the nova-compute.log shows the error.
2011-09-23 10:27:45,160 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-09-23 10:27:45,160 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-09-23 10:27:46,411 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-09-23 10:27:46,411 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-09-23 10:27:47,056 INFO nova.compute.manager [-] Found 1 in the database and 2 on the hypervisor.
2011-09-23 10:27:58,678 WARNING nova.virt.xenapi [-] Task [Async.host.call_plugin] OpaqueRef:2b20672c-f48e-1714-8ed6-513609ae1e3b status: failure ['XENAPI_PLUGIN_EXCEPTION', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.']
2011-09-23 10:27:58,679 ERROR nova.virt.xenapi.vmops [-] TIMEOUT: The call to version timed out. VM id=2; args={'path': '', 'dom_id': '4', 'id': '01b8df39-374d-45d4-b30d-59e80884ff85'}
2011-09-23 10:27:58,679 ERROR nova.virt.xenapi.vmops [-] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2011-09-23 10:28:29,738 WARNING nova.virt.xenapi [-] Task [Async.host.call_plugin] OpaqueRef:c206d84d-377d-b79c-7434-fb5d68a5f874 status: failure ['XENAPI_PLUGIN_EXCEPTION', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.']
2011-09-23 10:28:29,739 ERROR nova.virt.xenapi.vmops [-] TIMEOUT: The call to version timed out. VM id=2; args={'path': '', 'dom_id': '4', 'id': 'c593c2b6-52cb-45e8-be3c-98a490c30cce'}
2011-09-23 10:28:29,739 ERROR nova.virt.xenapi.vmops [-] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2011-09-23 10:28:47,077 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=9716) periodic_tasks /root/openstack/nova/nova/manager.py:111
2011-09-23 10:28:47,077 DEBUG nova.rpc [-] Making asynchronous fanout cast... from (pid=9716) fanout_cast /root/openstack/nova/nova/rpc/impl_kombu.py:754
2011-09-23 10:28:47,480 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-09-23 10:28:47,480 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-09-23 10:28:48,610 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-09-23 10:28:48,611 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-09-23 10:28:49,185 INFO nova.compute.manager [-] Found 1 in the database and 2 on the hypervisor.
============================================
Do I have to run something else in the xenserver (xcp) ? agent?
any ideas?
thanks!

Question information

Language:
English Edit question
Status:
Answered
For:
OpenStack Compute (nova) Edit question
Assignee:
No assignee Edit question
Last query:
Last reply:
Revision history for this message
Dan Prince (dan-prince) said :
#1

Hi Arturo,

Does the image your trying to boot have the openstack guest agent installed:

https://launchpad.net/openstack-guest-agents

When using XenServer nova communicates w/ the agent via XenStore on the hypervisor. In your case nova-compute is looking for a response from the agent (which is also stored in XenServer) and it is timing out.

Also, you might hit up comstud on IRC if you are looking for the latest agent builds.

Hope this helps.

Dan

Revision history for this message
Afef (afef-mdhaffar) said :
#2

Hi,

I got the same problem.
When I tried to install guest agent, I got this error (make check):

make[2]: Entering directory `/home/afef.mdhaffar/rackspace-openstack-guest-agents-unix-e8170bf'
Traceback (most recent call last):
  File "run_tests.py", line 38, in <module>
    tests.agent_test.run_tests(modules)
  File "/home/afef.mdhaffar/rackspace-openstack-guest-agents-unix-e8170bf/tests/agent_test.py", line 42, in run_tests
    test_suite = unittest.TestLoader().loadTestsFromNames(modules)
  File "/usr/lib/python2.7/unittest/loader.py", line 128, in loadTestsFromNames
    suites = [self.loadTestsFromName(name, module) for name in names]
  File "/usr/lib/python2.7/unittest/loader.py", line 100, in loadTestsFromName
    parent, obj = obj, getattr(obj, part)
AttributeError: 'module' object has no attribute 'test_freebsd_network'
make[2]: *** [check-local] Error 1
make[2]: Leaving directory `/home/afef.mdhaffar/rackspace-openstack-guest-agents-unix-e8170bf'
make[1]: *** [check-am] Error 2
make[1]: Leaving directory `/home/afef.mdhaffar/rackspace-openstack-guest-agents-unix-e8170bf'
make: *** [check-recursive] Error 1

Any idea to fix this problem ????

Thank you,
Afef

Revision history for this message
Johannes Erdfelt (johannes.erdfelt) said :
#3

I just pushed up a new branch which adds a minor new feature but also fixes the unit test problem you're seeing.

https://github.com/rackspace/openstack-guest-agents-unix/tree/add-network-label

Revision history for this message
John Garbutt (johngarbutt) said :
#4

That exception shouldn't actually be a problem if you don't need the functionality the agent gives you.

If you use cloud-init you should get things like ssh-key injection, and DHCP, if you are using it, will get the IP configuration setup properly.

But if you install the agent (linux or windows one) it gives you extra goodies like password reset. Obviously, in certain cases that can be a life saver!

Revision history for this message
John Garbutt (johngarbutt) said :
#5

Sorry my bad, got confused with dates here!

Revision history for this message
Afef (afef-mdhaffar) said :
#6

Hi all,

I installed the openstack guest agent on the image. But, I still have the same errors :
Any other way to solve it ?

Thank you,
Afef

--------------
2012-10-04 13:50:37 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:50:37 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:50:41 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:50:41 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '70', 'id': '0f8e915c-c1e0-4754-91f7-3a60d45d5c0e', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:50:41 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:51:12 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'XenstoreError', "cmd: ['xenstore-rm', '/local/domain/70/data/host/ecf13d5f-6733-4eb2-9ffb-c056772c2944']; returncode: 1; stderr: xenstore-rm: could not remove path /local/domain/70/data/host/ecf13d5f-6733-4eb2-9ffb-c056772c2944\n; stdout: "] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:51:12 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] The call to version returned an error: ['XENAPI_PLUGIN_FAILURE', 'version', 'XenstoreError', "cmd: ['xenstore-rm', '/local/domain/70/data/host/ecf13d5f-6733-4eb2-9ffb-c056772c2944']; returncode: 1; stderr: xenstore-rm: could not remove path /local/domain/70/data/host/ecf13d5f-6733-4eb2-9ffb-c056772c2944\n; stdout: "]. args={'dom_id': '70', 'id': 'ecf13d5f-6733-4eb2-9ffb-c056772c2944', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:51:12 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': '; stdout: ', 'returncode': 'error'}
2012-10-04 13:51:37 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:37 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=30089) _publish_service_capabilities /opt/stack/nova/nova/manager.py:231
2012-10-04 13:51:37 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=30089) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:384
2012-10-04 13:51:37 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:37 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 4 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:51:37 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:37 INFO nova.compute.manager [-] Updating bandwidth usage cache
2012-10-04 13:51:37 ERROR nova.manager [-] Error during ComputeManager._poll_bandwidth_usage: 'module' object has no attribute 'fetch_bandwidth'
2012-10-04 13:51:37 TRACE nova.manager Traceback (most recent call last):
2012-10-04 13:51:37 TRACE nova.manager File "/opt/stack/nova/nova/manager.py", line 175, in periodic_tasks
2012-10-04 13:51:37 TRACE nova.manager task(self, context)
2012-10-04 13:51:37 TRACE nova.manager File "/opt/stack/nova/nova/compute/manager.py", line 2543, in _poll_bandwidth_usage
2012-10-04 13:51:37 TRACE nova.manager bw_counters = self.driver.get_all_bw_counters(instances)
2012-10-04 13:51:37 TRACE nova.manager File "/opt/stack/nova/nova/virt/xenapi/driver.py", line 313, in get_all_bw_counters
2012-10-04 13:51:37 TRACE nova.manager all_counters = self._vmops.get_all_bw_counters()
2012-10-04 13:51:37 TRACE nova.manager File "/opt/stack/nova/nova/virt/xenapi/vmops.py", line 1221, in get_all_bw_counters
2012-10-04 13:51:37 TRACE nova.manager counters = vm_utils.fetch_bandwidth(self._session)
2012-10-04 13:51:37 TRACE nova.manager AttributeError: 'module' object has no attribute 'fetch_bandwidth'
2012-10-04 13:51:37 TRACE nova.manager
2012-10-04 13:51:37 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:37 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:37 DEBUG nova.utils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:51:37 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:51:38 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 3647 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:447
2012-10-04 13:51:38 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 40 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:448
2012-10-04 13:51:38 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:455
2012-10-04 13:51:39 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6143
2012-10-04 13:51:39 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 216
2012-10-04 13:51:39 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-10-04 13:51:39 INFO nova.compute.resource_tracker [-] Compute_service record updated for DevStackOSDomU
2012-10-04 13:51:39 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:39 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 11 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:51:39 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:39 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:39 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous call on network ... from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:351
2012-10-04 13:51:39 DEBUG nova.openstack.common.rpc.amqp [-] MSG_ID is 594a5d4a200549b3a8997b20621ac928 from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:354
2012-10-04 13:51:39 DEBUG nova.compute.manager [-] [instance: f6afe6b6-7767-44bb-9cc3-28ad2d306176] Updated the info_cache for instance from (pid=30089) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:2416
2012-10-04 13:51:39 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 31 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:51:39 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:39 DEBUG nova.compute.manager [-] FLAGS.reclaim_instance_interval <= 0, skipping... from (pid=30089) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:2752
2012-10-04 13:51:39 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:39 INFO nova.compute.manager [-] Updating host status
2012-10-04 13:51:39 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:51:40 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:51:43 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:51:43 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': 'fc6d3590-4961-4267-990e-e34c42e13fba', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:51:43 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:52:13 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:52:13 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': '8997e77f-009e-4030-832a-4b4581d2a4d0', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:52:13 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:52:40 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:40 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=30089) _publish_service_capabilities /opt/stack/nova/nova/manager.py:231
2012-10-04 13:52:40 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=30089) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:384
2012-10-04 13:52:40 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:40 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 3 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:52:40 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:40 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:40 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:40 DEBUG nova.utils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:52:40 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:52:41 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 3647 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:447
2012-10-04 13:52:41 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 40 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:448
2012-10-04 13:52:41 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:455
2012-10-04 13:52:41 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6143
2012-10-04 13:52:41 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 216
2012-10-04 13:52:41 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-10-04 13:52:41 INFO nova.compute.resource_tracker [-] Compute_service record updated for DevStackOSDomU
2012-10-04 13:52:41 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:41 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 10 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:52:41 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:41 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:41 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous call on network ... from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:351
2012-10-04 13:52:41 DEBUG nova.openstack.common.rpc.amqp [-] MSG_ID is 1ca213b811c744ddbe65f7cab084ed9b from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:354
2012-10-04 13:52:42 DEBUG nova.compute.manager [-] [instance: 64c3b0a7-2352-49fb-908f-eff4663b3d89] Updated the info_cache for instance from (pid=30089) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:2416
2012-10-04 13:52:42 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 30 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:52:42 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:42 DEBUG nova.compute.manager [-] FLAGS.reclaim_instance_interval <= 0, skipping... from (pid=30089) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:2752
2012-10-04 13:52:42 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:42 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:52:44 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:52:44 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': '710be6f6-4f49-4262-a657-ab8bfc107e52', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:52:44 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:53:15 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:53:15 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': 'aed3fb65-df0b-42fa-ad4d-f2ac6a34a0b3', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:53:15 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:53:42 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:42 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=30089) _publish_service_capabilities /opt/stack/nova/nova/manager.py:231
2012-10-04 13:53:42 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=30089) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:384
2012-10-04 13:53:42 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:42 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 2 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:53:42 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:42 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:42 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:42 DEBUG nova.utils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:53:42 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:53:43 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 3647 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:447
2012-10-04 13:53:43 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 40 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:448
2012-10-04 13:53:43 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:455
2012-10-04 13:53:43 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6143
2012-10-04 13:53:43 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 216
2012-10-04 13:53:43 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-10-04 13:53:43 INFO nova.compute.resource_tracker [-] Compute_service record updated for DevStackOSDomU
2012-10-04 13:53:43 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:43 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 9 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:53:43 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:43 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:43 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous call on network ... from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:351
2012-10-04 13:53:43 DEBUG nova.openstack.common.rpc.amqp [-] MSG_ID is d943cd259afa4c7f84c3e0e4070e334d from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:354
2012-10-04 13:53:43 DEBUG nova.compute.manager [-] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Updated the info_cache for instance from (pid=30089) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:2416
2012-10-04 13:53:43 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 29 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:53:43 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:43 DEBUG nova.compute.manager [-] FLAGS.reclaim_instance_interval <= 0, skipping... from (pid=30089) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:2752
2012-10-04 13:53:43 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:43 INFO nova.compute.manager [-] Updating host status
2012-10-04 13:53:43 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:53:44 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:53:45 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:53:45 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': 'c7b60026-d8d9-4b71-9aed-4b1a9b827589', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:53:45 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:54:16 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:54:16 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': 'ec97f326-cc28-46e4-a36c-2d0a6f7d9492', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:54:16 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:54:44 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:44 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=30089) _publish_service_capabilities /opt/stack/nova/nova/manager.py:231
2012-10-04 13:54:44 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=30089) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:384
2012-10-04 13:54:44 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:44 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 1 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:54:44 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:44 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:44 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:44 DEBUG nova.utils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:54:44 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:54:45 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 3647 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:447
2012-10-04 13:54:45 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 40 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:448
2012-10-04 13:54:45 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:455
2012-10-04 13:54:45 AUDIT nova.compute.resource_tracker [-] Expiring resource claim 718f906a-0d39-4570-a214-1c7735421fef
2012-10-04 13:54:45 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6143
2012-10-04 13:54:45 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 216
2012-10-04 13:54:45 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-10-04 13:54:45 INFO nova.compute.resource_tracker [-] Compute_service record updated for DevStackOSDomU
2012-10-04 13:54:45 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:45 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 8 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:54:45 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:45 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:45 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous call on network ... from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:351
2012-10-04 13:54:45 DEBUG nova.openstack.common.rpc.amqp [-] MSG_ID is 457bcc4250b840909bdc8820cd01f554 from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:354
2012-10-04 13:54:46 DEBUG nova.compute.manager [-] [instance: f6afe6b6-7767-44bb-9cc3-28ad2d306176] Updated the info_cache for instance from (pid=30089) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:2416
2012-10-04 13:54:46 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 28 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:54:46 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:46 DEBUG nova.compute.manager [-] FLAGS.reclaim_instance_interval <= 0, skipping... from (pid=30089) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:2752
2012-10-04 13:54:46 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:46 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:54:47 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:54:47 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': 'da9ec220-5e88-4900-a240-b6ec82715d9d', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:54:47 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:55:17 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'version', 'PluginError', 'TIMEOUT: No response from agent within 30 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:55:17 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to version timed out. args={'dom_id': '-1', 'id': '3bf1f07e-199e-496a-96c4-e23b945d8eb5', 'timeout': '30', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:55:17 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to query agent version: {'message': 'TIMEOUT: No response from agent within 30 seconds.', 'returncode': 'timeout'}
2012-10-04 13:55:17 INFO nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Reached maximum time attempting to query agent version
2012-10-04 13:55:17 DEBUG nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Resetting network from (pid=30089) resetnetwork /opt/stack/nova/nova/virt/xenapi/agent.py:216
2012-10-04 13:55:46 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:46 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=30089) _publish_service_capabilities /opt/stack/nova/nova/manager.py:231
2012-10-04 13:55:46 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=30089) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:384
2012-10-04 13:55:46 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:46 DEBUG nova.manager [-] Running periodic task ComputeManager._sync_power_states from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:47 WARNING nova.compute.manager [-] Found 3 in the database and 5 on the hypervisor.
2012-10-04 13:55:47 INFO nova.compute.manager [-] [instance: 718f906a-0d39-4570-a214-1c7735421fef] During sync_power_state the instance has a pending task. Skip.
2012-10-04 13:55:47 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:47 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:47 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:47 DEBUG nova.utils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:55:47 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:55:48 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 3647 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:447
2012-10-04 13:55:48 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 40 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:448
2012-10-04 13:55:48 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:455
2012-10-04 13:55:48 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6143
2012-10-04 13:55:48 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 216
2012-10-04 13:55:48 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-10-04 13:55:48 INFO nova.compute.resource_tracker [-] Compute_service record updated for DevStackOSDomU
2012-10-04 13:55:48 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:48 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 7 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:55:48 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:48 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:48 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous call on network ... from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:351
2012-10-04 13:55:48 DEBUG nova.openstack.common.rpc.amqp [-] MSG_ID is 4769f3bdb175475c9110e6642d0ae751 from (pid=30089) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:354
2012-10-04 13:55:49 DEBUG nova.compute.manager [-] [instance: 64c3b0a7-2352-49fb-908f-eff4663b3d89] Updated the info_cache for instance from (pid=30089) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:2416
2012-10-04 13:55:49 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 27 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:55:49 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:49 DEBUG nova.compute.manager [-] FLAGS.reclaim_instance_interval <= 0, skipping... from (pid=30089) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:2752
2012-10-04 13:55:49 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:55:49 INFO nova.compute.manager [-] Updating host status
2012-10-04 13:55:49 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:55:50 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:56:18 DEBUG nova.virt.xenapi.driver [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got exception: ['XENAPI_PLUGIN_FAILURE', 'resetnetwork', 'PluginError', 'TIMEOUT: No response from agent within 60 seconds.'] from (pid=30089) _unwrap_plugin_exceptions /opt/stack/nova/nova/virt/xenapi/driver.py:728
2012-10-04 13:56:18 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] TIMEOUT: The call to resetnetwork timed out. args={'dom_id': '-1', 'id': 'acdb87cb-f285-4e3b-bf3b-436149a235ac', 'timeout': '60', 'host_uuid': '5471348a-5b5c-9bdf-ce4f-f375127879b5'}
2012-10-04 13:56:18 ERROR nova.virt.xenapi.agent [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Failed to reset network: {'message': 'TIMEOUT: No response from agent within 60 seconds.', 'returncode': 'timeout'}
2012-10-04 13:56:18 DEBUG nova.virt.xenapi.vmops [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Updating progress to 88 from (pid=30089) bump_progress /opt/stack/nova/nova/virt/xenapi/vmops.py:131
2012-10-04 13:56:18 DEBUG nova.virt.xenapi.vmops [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Updating progress to 100 from (pid=30089) bump_progress /opt/stack/nova/nova/virt/xenapi/vmops.py:131
2012-10-04 13:56:18 DEBUG nova.compute.manager [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] [instance: 718f906a-0d39-4570-a214-1c7735421fef] Checking state from (pid=30089) _get_power_state /opt/stack/nova/nova/compute/manager.py:339
2012-10-04 13:56:18 DEBUG nova.utils [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got semaphore "compute_resources" for method "update_usage"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:56:18 DEBUG nova.utils [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Got semaphore "compute_resources" for method "finish_resource_claim"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:56:18 INFO nova.compute.resource_tracker [req-4d8a0269-0eb4-4a17-a9fc-29a7d047dc2b demo demo] Can't find claim 718f906a-0d39-4570-a214-1c7735421fef. It may have been 'finished' twice, or it has already timed out.
2012-10-04 13:56:50 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:56:50 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=30089) _publish_service_capabilities /opt/stack/nova/nova/manager.py:231
2012-10-04 13:56:50 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=30089) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:384
2012-10-04 13:56:50 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:56:50 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 10 ticks left until next run from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-10-04 13:56:50 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:56:50 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:56:50 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=30089) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-10-04 13:56:50 DEBUG nova.utils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=30089) inner /opt/stack/nova/nova/utils.py:721
2012-10-04 13:56:50 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=30089) update_status /opt/stack/nova/nova/virt/xenapi/host.py:148
2012-10-04 13:56:51 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 3647 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:447
2012-10-04 13:56:51 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 40 from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:448
2012-10-04 13:56:51 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=30089) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:455
2012-10-04 13:56:51 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6143
2012-10-04 13:56:5

Can you help with this problem?

Provide an answer of your own, or ask arturo lorenzo for more information if necessary.

To post a message you must log in.