openstack team mailing list archive

Thread
Date
can not launch an instance + RPC timeout + nova-network does not start dnsmasq

To: openstack@xxxxxxxxxxxxxxxxxxx
From: Afef MDHAFFAR <afef.mdhaffar@xxxxxxxxx>
Date: Mon, 10 Dec 2012 17:59:19 +0100
Hi all,

I installed openstack (folsom release) on ubuntu 12.04 + XCP.
All services seem to be running.
However nova-network does not start dnsmasq -- and the interface xapi0 is
missing.
I can not launch an instance , and I got the following logs on nova-compute.
Please try to help to fix this issue.
Thank you,
Afef
------
2012-12-10 16:51:14 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 16:51:15 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_unconfirmed_resizes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:51:37 ERROR nova.openstack.common.rpc.common
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] Timed out waiting
for RPC response: timed out
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common Traceback (most
recent call last):
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in
ensure
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     return
method(*args, **kwargs)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in
_consume
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     return
self.connection.drain_events(timeout=timeout)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in
drain_events
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     return
self.transport.drain_events(self.connection, **kwargs)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200,
in drain_events
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     return
connection.drain_events(**kwargs)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50,
in drain_events
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     return
self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56,
in wait_multi
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common
chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104,
in _wait_multiple
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     channel,
method_sig, args, content = self.read_timeout(timeout)
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86,
in read_timeout
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     return
self.method_reader.read_method()
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common   File
"/usr/local/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py",
line 215, in read_method
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common timeout: timed
out
2012-12-10 16:51:37 TRACE nova.openstack.common.rpc.common
2012-12-10 16:51:37 DEBUG nova.openstack.common.rpc.amqp
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] Making asynchronous
call on conductor ... from (pid=28401) multicall
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:359
2012-12-10 16:51:37 DEBUG nova.openstack.common.rpc.amqp
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] MSG_ID is
806e29cdea2640b9a03a6990d793c57b from (pid=28401) multicall
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:362
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager.publish_service_capabilities from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.manager [-] Notifying Schedulers of
capabilities ... from (pid=28401) publish_service_capabilities
/opt/stack/nova/nova/manager.py:257
2012-12-10 16:52:15 DEBUG nova.openstack.common.rpc.amqp [-] Making
asynchronous fanout cast... from (pid=28401) fanout_cast
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager._heal_instance_info_cache from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rescued_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_volume_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_bandwidth_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.manager [-] Skipping
ComputeManager._sync_power_states, 7 ticks left until next run from
(pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager._instance_usage_audit from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.manager [-] Running periodic task
ComputeManager.update_available_resource from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:15 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 16:52:15 DEBUG nova.openstack.common.lockutils [-] Got semaphore
"compute_resources" for method "update_available_resource"... from
(pid=28401) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 16:52:15 AUDIT nova.compute.resource_tracker [-] Auditing
locally available compute resources
2012-12-10 16:52:15 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 16:52:16 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free ram (MB): 4938 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 16:52:16 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free disk (GB): 218 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 16:52:16 DEBUG nova.compute.resource_tracker [-] Hypervisor:
VCPU information unavailable from (pid=28401)
_report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 16:52:16 AUDIT nova.compute.resource_tracker [-] Free ram (MB):
7679
2012-12-10 16:52:16 AUDIT nova.compute.resource_tracker [-] Free disk (GB):
225
2012-12-10 16:52:16 AUDIT nova.compute.resource_tracker [-] Free VCPU
information unavailable
2012-12-10 16:52:16 INFO nova.compute.resource_tracker [-] Compute_service
record updated for openstackDomU
2012-12-10 16:52:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rebooting_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:16 DEBUG nova.manager [-] Skipping
ComputeManager._cleanup_running_deleted_instances, 27 ticks left until next
run from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 16:52:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._check_instance_build_time from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:16 DEBUG nova.manager [-] Skipping
ComputeManager._run_image_cache_manager_pass, 37 ticks left until next run
from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 16:52:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._reclaim_queued_deletes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:16 DEBUG nova.compute.manager [-]
CONF.reclaim_instance_interval <= 0, skipping... from (pid=28401)
_reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3215
2012-12-10 16:52:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._report_driver_status from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_unconfirmed_resizes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
2012-12-10 16:52:37 ERROR nova.openstack.common.rpc.common
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] Timed out waiting
for RPC response: timed out
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common Traceback (most
recent call last):
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in
ensure
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     return
method(*args, **kwargs)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in
_consume
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     return
self.connection.drain_events(timeout=timeout)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in
drain_events
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     return
self.transport.drain_events(self.connection, **kwargs)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200,
in drain_events
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     return
connection.drain_events(**kwargs)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50,
in drain_events
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     return
self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56,
in wait_multi
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common
chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104,
in _wait_multiple
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     channel,
method_sig, args, content = self.read_timeout(timeout)
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86,
in read_timeout
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     return
self.method_reader.read_method()
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common   File
"/usr/local/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py",
line 215, in read_method
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common timeout: timed
out
2012-12-10 16:52:37 TRACE nova.openstack.common.rpc.common
ERROR:root:Original exception being dropped: ['Traceback (most recent call
last):\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 605, in
_run_instance\n    self._start_building(context, instance)\n', '  File
"/opt/stack/nova/nova/compute/manager.py", line 835, in _start_building\n
 None))\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 349, in
_instance_update\n    **kwargs)\n', '  File
"/opt/stack/nova/nova/conductor/api.py", line 78, in instance_update\n
 updates)\n', '  File "/opt/stack/nova/nova/conductor/rpcapi.py", line 48,
in instance_update\n    updates=updates_p))\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call\n
 return rpc.call(context, self._get_topic(topic), msg, timeout)\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in
call\n    return _get_impl().call(cfg.CONF, context, topic, msg,
timeout)\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in
call\n    rpc_amqp.get_connection_pool(conf, Connection))\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 376, in call\n
 rv = list(rv)\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 337, in
__iter__\n    self.done()\n', '  File "/usr/lib/python2.7/contextlib.py",
line 24, in __exit__\n    self.gen.next()\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 334, in
__iter__\n    self._iterator.next()\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in
iterconsume\n    yield self.ensure(_error_callback, _consume)\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in
ensure\n    error_callback(e)\n', '  File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in
_error_callback\n    raise rpc_common.Timeout()\n', 'Timeout: Timeout while
waiting on RPC response.\n']
2012-12-10 16:52:37 DEBUG nova.openstack.common.rpc.amqp
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] Making asynchronous
call on conductor ... from (pid=28401) multicall
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:359
DEBUG:nova.openstack.common.rpc.amqp:Making asynchronous call on conductor
...
2012-12-10 16:52:37 DEBUG nova.openstack.common.rpc.amqp
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] MSG_ID is
bca57b2f78434b58beac25467d23177c from (pid=28401) multicall
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:362
DEBUG:nova.openstack.common.rpc.amqp:MSG_ID is
bca57b2f78434b58beac25467d23177c
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager.publish_service_capabilities from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager.publish_service_capabilities
2012-12-10 16:53:16 DEBUG nova.manager [-] Notifying Schedulers of
capabilities ... from (pid=28401) publish_service_capabilities
/opt/stack/nova/nova/manager.py:257
DEBUG:nova.manager:Notifying Schedulers of capabilities ...
2012-12-10 16:53:16 DEBUG nova.openstack.common.rpc.amqp [-] Making
asynchronous fanout cast... from (pid=28401) fanout_cast
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
DEBUG:nova.openstack.common.rpc.amqp:Making asynchronous fanout cast...
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._heal_instance_info_cache from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._heal_instance_info_cache
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rescued_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_rescued_instances
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_volume_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_volume_usage
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_bandwidth_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_bandwidth_usage
2012-12-10 16:53:16 DEBUG nova.manager [-] Skipping
ComputeManager._sync_power_states, 6 ticks left until next run from
(pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._sync_power_states, 6 ticks left
until next run
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager._instance_usage_audit from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._instance_usage_audit
2012-12-10 16:53:16 DEBUG nova.manager [-] Running periodic task
ComputeManager.update_available_resource from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager.update_available_resource
2012-12-10 16:53:16 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:53:17 DEBUG nova.openstack.common.lockutils [-] Got semaphore
"compute_resources" for method "update_available_resource"... from
(pid=28401) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
DEBUG:nova.openstack.common.lockutils:Got semaphore "compute_resources" for
method "update_available_resource"...
2012-12-10 16:53:17 AUDIT nova.compute.resource_tracker [-] Auditing
locally available compute resources
AUDIT:nova.compute.resource_tracker:Auditing locally available compute
resources
2012-12-10 16:53:17 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:53:17 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free ram (MB): 4938 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:322
DEBUG:nova.compute.resource_tracker:Hypervisor: free ram (MB): 4938
2012-12-10 16:53:17 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free disk (GB): 218 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:323
DEBUG:nova.compute.resource_tracker:Hypervisor: free disk (GB): 218
2012-12-10 16:53:17 DEBUG nova.compute.resource_tracker [-] Hypervisor:
VCPU information unavailable from (pid=28401)
_report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:330
DEBUG:nova.compute.resource_tracker:Hypervisor: VCPU information unavailable
2012-12-10 16:53:17 AUDIT nova.compute.resource_tracker [-] Free ram (MB):
7679
AUDIT:nova.compute.resource_tracker:Free ram (MB): 7679
2012-12-10 16:53:17 AUDIT nova.compute.resource_tracker [-] Free disk (GB):
225
AUDIT:nova.compute.resource_tracker:Free disk (GB): 225
2012-12-10 16:53:17 AUDIT nova.compute.resource_tracker [-] Free VCPU
information unavailable
AUDIT:nova.compute.resource_tracker:Free VCPU information unavailable
2012-12-10 16:53:18 INFO nova.compute.resource_tracker [-] Compute_service
record updated for openstackDomU
INFO:nova.compute.resource_tracker:Compute_service record updated for
openstackDomU
2012-12-10 16:53:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rebooting_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_rebooting_instances
2012-12-10 16:53:18 DEBUG nova.manager [-] Skipping
ComputeManager._cleanup_running_deleted_instances, 26 ticks left until next
run from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping
ComputeManager._cleanup_running_deleted_instances, 26 ticks left until next
run
2012-12-10 16:53:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._check_instance_build_time from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._check_instance_build_time
2012-12-10 16:53:18 DEBUG nova.manager [-] Skipping
ComputeManager._run_image_cache_manager_pass, 36 ticks left until next run
from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._run_image_cache_manager_pass,
36 ticks left until next run
2012-12-10 16:53:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._reclaim_queued_deletes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._reclaim_queued_deletes
2012-12-10 16:53:18 DEBUG nova.compute.manager [-]
CONF.reclaim_instance_interval <= 0, skipping... from (pid=28401)
_reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3215
DEBUG:nova.compute.manager:CONF.reclaim_instance_interval <= 0, skipping...
2012-12-10 16:53:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._report_driver_status from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._report_driver_status
2012-12-10 16:53:18 INFO nova.compute.manager [-] Updating host status
INFO:nova.compute.manager:Updating host status
2012-12-10 16:53:18 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:53:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_unconfirmed_resizes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_unconfirmed_resizes
2012-12-10 16:53:37 ERROR nova.openstack.common.rpc.common
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] Timed out waiting
for RPC response: timed out
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common Traceback (most
recent call last):
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in
ensure
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
method(*args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in
_consume
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.connection.drain_events(timeout=timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in
drain_events
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.transport.drain_events(self.connection, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200,
in drain_events
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
connection.drain_events(**kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50,
in drain_events
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56,
in wait_multi
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common
chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104,
in _wait_multiple
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     channel,
method_sig, args, content = self.read_timeout(timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86,
in read_timeout
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.method_reader.read_method()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/local/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py",
line 215, in read_method
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common timeout: timed
out
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common
ERROR:nova.openstack.common.rpc.common:Timed out waiting for RPC response:
timed out
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common Traceback (most
recent call last):
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in
ensure
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
method(*args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in
_consume
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.connection.drain_events(timeout=timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in
drain_events
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.transport.drain_events(self.connection, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200,
in drain_events
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
connection.drain_events(**kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50,
in drain_events
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56,
in wait_multi
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common
chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104,
in _wait_multiple
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     channel,
method_sig, args, content = self.read_timeout(timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86,
in read_timeout
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     return
self.method_reader.read_method()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common   File
"/usr/local/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py",
line 215, in read_method
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common timeout: timed
out
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.common
2012-12-10 16:53:37 ERROR nova.openstack.common.rpc.amqp
[req-2c7c1df0-e6f7-4a13-83d6-c51e23d0fcbb admin admin] Exception during
message handling
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp Traceback (most
recent call last):
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 277, in
_process_data
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     rval =
self.proxy.dispatch(ctxt, version, method, **args)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/dispatcher.py", line 147, in
dispatch
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
getattr(proxyobj, method)(ctxt, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/exception.py", line 115, in wrapped
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     temp_level,
payload)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/exception.py", line 90, in wrapped
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
f(*args, **kw)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 212, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     pass
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 198, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
function(self, context, *args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 239, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
kwargs['instance']['uuid'], e, sys.exc_info())
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 227, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
function(self, context, *args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 976, in run_instance
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
do_run_instance()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/lockutils.py", line 228, in inner
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     retval =
f(*args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 975, in do_run_instance
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
admin_password, is_first_time, node, instance)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 649, in _run_instance
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
self._set_instance_error_state(context, instance['uuid'])
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 361, in
_set_instance_error_state
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
vm_state=vm_states.ERROR)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 349, in _instance_update
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/conductor/api.py", line 78, in instance_update
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     updates)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/conductor/rpcapi.py", line 48, in instance_update
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
updates=updates_p))
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
rpc.call(context, self._get_topic(topic), msg, timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
_get_impl().call(cfg.CONF, context, topic, msg, timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
rpc_amqp.get_connection_pool(conf, Connection))
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 376, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     rv = list(rv)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 337, in __iter__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.done()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 334, in __iter__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
self._iterator.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in
iterconsume
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     yield
self.ensure(_error_callback, _consume)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in
ensure
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
error_callback(e)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in
_error_callback
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     raise
rpc_common.Timeout()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp Timeout: Timeout
while waiting on RPC response.
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
ERROR:nova.openstack.common.rpc.amqp:Exception during message handling
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp Traceback (most
recent call last):
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 277, in
_process_data
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     rval =
self.proxy.dispatch(ctxt, version, method, **args)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/dispatcher.py", line 147, in
dispatch
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
getattr(proxyobj, method)(ctxt, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/exception.py", line 115, in wrapped
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     temp_level,
payload)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/exception.py", line 90, in wrapped
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
f(*args, **kw)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 212, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     pass
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 198, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
function(self, context, *args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 239, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
kwargs['instance']['uuid'], e, sys.exc_info())
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 227, in decorated_function
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
function(self, context, *args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 976, in run_instance
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
do_run_instance()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/lockutils.py", line 228, in inner
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     retval =
f(*args, **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 975, in do_run_instance
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
admin_password, is_first_time, node, instance)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 649, in _run_instance
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
self._set_instance_error_state(context, instance['uuid'])
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 361, in
_set_instance_error_state
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
vm_state=vm_states.ERROR)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/compute/manager.py", line 349, in _instance_update
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     **kwargs)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/conductor/api.py", line 78, in instance_update
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     updates)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/conductor/rpcapi.py", line 48, in instance_update
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
updates=updates_p))
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
rpc.call(context, self._get_topic(topic), msg, timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     return
_get_impl().call(cfg.CONF, context, topic, msg, timeout)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
rpc_amqp.get_connection_pool(conf, Connection))
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 376, in call
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     rv = list(rv)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 337, in __iter__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.done()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 334, in __iter__
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
self._iterator.next()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in
iterconsume
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     yield
self.ensure(_error_callback, _consume)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in
ensure
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
error_callback(e)
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp   File
"/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in
_error_callback
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp     raise
rpc_common.Timeout()
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp Timeout: Timeout
while waiting on RPC response.
2012-12-10 16:53:37 TRACE nova.openstack.common.rpc.amqp
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager.publish_service_capabilities from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager.publish_service_capabilities
2012-12-10 16:54:18 DEBUG nova.manager [-] Notifying Schedulers of
capabilities ... from (pid=28401) publish_service_capabilities
/opt/stack/nova/nova/manager.py:257
DEBUG:nova.manager:Notifying Schedulers of capabilities ...
2012-12-10 16:54:18 DEBUG nova.openstack.common.rpc.amqp [-] Making
asynchronous fanout cast... from (pid=28401) fanout_cast
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
DEBUG:nova.openstack.common.rpc.amqp:Making asynchronous fanout cast...
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._heal_instance_info_cache from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._heal_instance_info_cache
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rescued_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_rescued_instances
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_volume_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_volume_usage
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_bandwidth_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_bandwidth_usage
2012-12-10 16:54:18 DEBUG nova.manager [-] Skipping
ComputeManager._sync_power_states, 5 ticks left until next run from
(pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._sync_power_states, 5 ticks left
until next run
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager._instance_usage_audit from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._instance_usage_audit
2012-12-10 16:54:18 DEBUG nova.manager [-] Running periodic task
ComputeManager.update_available_resource from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager.update_available_resource
2012-12-10 16:54:18 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:54:19 DEBUG nova.openstack.common.lockutils [-] Got semaphore
"compute_resources" for method "update_available_resource"... from
(pid=28401) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
DEBUG:nova.openstack.common.lockutils:Got semaphore "compute_resources" for
method "update_available_resource"...
2012-12-10 16:54:19 AUDIT nova.compute.resource_tracker [-] Auditing
locally available compute resources
AUDIT:nova.compute.resource_tracker:Auditing locally available compute
resources
2012-12-10 16:54:19 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:54:19 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free ram (MB): 4938 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:322
DEBUG:nova.compute.resource_tracker:Hypervisor: free ram (MB): 4938
2012-12-10 16:54:19 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free disk (GB): 218 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:323
DEBUG:nova.compute.resource_tracker:Hypervisor: free disk (GB): 218
2012-12-10 16:54:19 DEBUG nova.compute.resource_tracker [-] Hypervisor:
VCPU information unavailable from (pid=28401)
_report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:330
DEBUG:nova.compute.resource_tracker:Hypervisor: VCPU information unavailable
2012-12-10 16:54:19 AUDIT nova.compute.resource_tracker [-] Free ram (MB):
7679
AUDIT:nova.compute.resource_tracker:Free ram (MB): 7679
2012-12-10 16:54:19 AUDIT nova.compute.resource_tracker [-] Free disk (GB):
225
AUDIT:nova.compute.resource_tracker:Free disk (GB): 225
2012-12-10 16:54:19 AUDIT nova.compute.resource_tracker [-] Free VCPU
information unavailable
AUDIT:nova.compute.resource_tracker:Free VCPU information unavailable
2012-12-10 16:54:19 INFO nova.compute.resource_tracker [-] Compute_service
record updated for openstackDomU
INFO:nova.compute.resource_tracker:Compute_service record updated for
openstackDomU
2012-12-10 16:54:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rebooting_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_rebooting_instances
2012-12-10 16:54:19 DEBUG nova.manager [-] Skipping
ComputeManager._cleanup_running_deleted_instances, 25 ticks left until next
run from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping
ComputeManager._cleanup_running_deleted_instances, 25 ticks left until next
run
2012-12-10 16:54:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._check_instance_build_time from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._check_instance_build_time
2012-12-10 16:54:19 DEBUG nova.manager [-] Skipping
ComputeManager._run_image_cache_manager_pass, 35 ticks left until next run
from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._run_image_cache_manager_pass,
35 ticks left until next run
2012-12-10 16:54:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._reclaim_queued_deletes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._reclaim_queued_deletes
2012-12-10 16:54:19 DEBUG nova.compute.manager [-]
CONF.reclaim_instance_interval <= 0, skipping... from (pid=28401)
_reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3215
DEBUG:nova.compute.manager:CONF.reclaim_instance_interval <= 0, skipping...
2012-12-10 16:54:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._report_driver_status from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._report_driver_status
2012-12-10 16:54:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_unconfirmed_resizes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_unconfirmed_resizes
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager.publish_service_capabilities from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager.publish_service_capabilities
2012-12-10 16:55:19 DEBUG nova.manager [-] Notifying Schedulers of
capabilities ... from (pid=28401) publish_service_capabilities
/opt/stack/nova/nova/manager.py:257
DEBUG:nova.manager:Notifying Schedulers of capabilities ...
2012-12-10 16:55:19 DEBUG nova.openstack.common.rpc.amqp [-] Making
asynchronous fanout cast... from (pid=28401) fanout_cast
/opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
DEBUG:nova.openstack.common.rpc.amqp:Making asynchronous fanout cast...
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._heal_instance_info_cache from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._heal_instance_info_cache
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rescued_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_rescued_instances
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_volume_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_volume_usage
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_bandwidth_usage from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_bandwidth_usage
2012-12-10 16:55:19 DEBUG nova.manager [-] Skipping
ComputeManager._sync_power_states, 4 ticks left until next run from
(pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._sync_power_states, 4 ticks left
until next run
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager._instance_usage_audit from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._instance_usage_audit
2012-12-10 16:55:19 DEBUG nova.manager [-] Running periodic task
ComputeManager.update_available_resource from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager.update_available_resource
2012-12-10 16:55:19 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:55:20 DEBUG nova.openstack.common.lockutils [-] Got semaphore
"compute_resources" for method "update_available_resource"... from
(pid=28401) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
DEBUG:nova.openstack.common.lockutils:Got semaphore "compute_resources" for
method "update_available_resource"...
2012-12-10 16:55:20 AUDIT nova.compute.resource_tracker [-] Auditing
locally available compute resources
AUDIT:nova.compute.resource_tracker:Auditing locally available compute
resources
2012-12-10 16:55:20 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:55:20 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free ram (MB): 4938 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:322
DEBUG:nova.compute.resource_tracker:Hypervisor: free ram (MB): 4938
2012-12-10 16:55:20 DEBUG nova.compute.resource_tracker [-] Hypervisor:
free disk (GB): 218 from (pid=28401) _report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:323
DEBUG:nova.compute.resource_tracker:Hypervisor: free disk (GB): 218
2012-12-10 16:55:20 DEBUG nova.compute.resource_tracker [-] Hypervisor:
VCPU information unavailable from (pid=28401)
_report_hypervisor_resource_view
/opt/stack/nova/nova/compute/resource_tracker.py:330
DEBUG:nova.compute.resource_tracker:Hypervisor: VCPU information unavailable
2012-12-10 16:55:21 AUDIT nova.compute.resource_tracker [-] Free ram (MB):
7679
AUDIT:nova.compute.resource_tracker:Free ram (MB): 7679
2012-12-10 16:55:21 AUDIT nova.compute.resource_tracker [-] Free disk (GB):
225
AUDIT:nova.compute.resource_tracker:Free disk (GB): 225
2012-12-10 16:55:21 AUDIT nova.compute.resource_tracker [-] Free VCPU
information unavailable
AUDIT:nova.compute.resource_tracker:Free VCPU information unavailable
2012-12-10 16:55:21 INFO nova.compute.resource_tracker [-] Compute_service
record updated for openstackDomU
INFO:nova.compute.resource_tracker:Compute_service record updated for
openstackDomU
2012-12-10 16:55:21 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_rebooting_instances from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_rebooting_instances
2012-12-10 16:55:21 DEBUG nova.manager [-] Skipping
ComputeManager._cleanup_running_deleted_instances, 24 ticks left until next
run from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping
ComputeManager._cleanup_running_deleted_instances, 24 ticks left until next
run
2012-12-10 16:55:21 DEBUG nova.manager [-] Running periodic task
ComputeManager._check_instance_build_time from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._check_instance_build_time
2012-12-10 16:55:21 DEBUG nova.manager [-] Skipping
ComputeManager._run_image_cache_manager_pass, 34 ticks left until next run
from (pid=28401) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._run_image_cache_manager_pass,
34 ticks left until next run
2012-12-10 16:55:21 DEBUG nova.manager [-] Running periodic task
ComputeManager._reclaim_queued_deletes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._reclaim_queued_deletes
2012-12-10 16:55:21 DEBUG nova.compute.manager [-]
CONF.reclaim_instance_interval <= 0, skipping... from (pid=28401)
_reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3215
DEBUG:nova.compute.manager:CONF.reclaim_instance_interval <= 0, skipping...
2012-12-10 16:55:21 DEBUG nova.manager [-] Running periodic task
ComputeManager._report_driver_status from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._report_driver_status
2012-12-10 16:55:21 INFO nova.compute.manager [-] Updating host status
INFO:nova.compute.manager:Updating host status
2012-12-10 16:55:21 DEBUG nova.virt.xenapi.host [-] Updating host stats
from (pid=28401) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 16:55:21 DEBUG nova.manager [-] Running periodic task
ComputeManager._poll_unconfirmed_resizes from (pid=28401) periodic_tasks
/opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task
ComputeManager._poll_unconfirmed_resizes
Follow ups

Re: can not launch an instance + RPC timeout + nova-network does not start dnsmasq
From: John Garbutt, 2012-12-10