David, That 16591 seems to be rpc timeout related http://logs.openstack.org/16591/1/gate/gate-tempest-devstack-vm/19391/logs/screen-n-cpu.txt.gz -- dims 2012-11-20 23:16:14 21855 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances periodic_tasks /opt/stack/nova/nova/manager.py:171 2012-11-20 23:16:14 21855 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 28 ticks left until next run periodic_tasks /opt/stack/nova/nova/manager.py:166 2012-11-20 23:16:14 21855 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time periodic_tasks /opt/stack/nova/nova/manager.py:171 2012-11-20 23:16:14 21855 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache periodic_tasks /opt/stack/nova/nova/manager.py:171 2012-11-20 23:16:14 21855 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous call on network ... multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:352 2012-11-20 23:16:14 21855 DEBUG nova.openstack.common.rpc.amqp [-] MSG_ID is e0b7dcdbf50f4ef99c907163773d8281 multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:355 2012-11-20 23:16:39 21855 ERROR nova.openstack.common.rpc.common [-] Timed out waiting for RPC response: timed out 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common Traceback (most recent call last): 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in ensure 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common return method(*args, **kwargs) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in _consume 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common return self.connection.drain_events(timeout=timeout) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/usr/local/lib/python2.7/dist-packages/kombu/connection.py", line 110, in drain_events 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common return self.transport.drain_events(self.connection, **kwargs) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/usr/local/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200, in drain_events 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common return connection.drain_events(**kwargs) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/usr/local/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50, in drain_events 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common return self.wait_multi(self.channels.values(), timeout=timeout) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/usr/local/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56, in wait_multi 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common chanmap.keys(), allowed_methods, timeout=timeout) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/usr/local/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104, in _wait_multiple 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common channel, method_sig, args, content = self.read_timeout(timeout) 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common File "/usr/local/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86, in read_timeout 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common return self.method_reader.read_method() 2012-11-20 23:16:39 21855 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-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common raise m 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common timeout: timed out 2012-11-20 23:16:39 21855 TRACE nova.openstack.common.rpc.common 2012-11-20 23:16:39 ERROR nova.compute.manager [req-6a569cb6-8802-45f3-bf8d-f446845bfdd1 demo demo] [instance: 99e14d05-f48b-4e87-94ce-5e54cada913a] Error: ['Traceback (most recent call last):\n', ' File "/opt/stack/nova/nova/compute/manager.py", line 593, in _run_instance\n requested_networks)\n', ' File "/opt/stack/nova/nova/compute/manager.py", line 821, in _allocate_network\n requested_networks=requested_networks)\n', ' File "/opt/stack/nova/nova/network/api.py", line 43, in wrapper\n res = f(self, context, *args, **kwargs)\n', ' File "/opt/stack/nova/nova/network/api.py", line 200, in allocate_for_instance\n nw_info = self.network_rpcapi.allocate_for_instance(context, **args)\n', ' File "/opt/stack/nova/nova/network/rpcapi.py", line 144, in allocate_for_instance\n vpn=vpn, requested_networks=requested_networks))\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 369, in call\n rv = list(rv)\n', ' File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 330, 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 327, 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-11-20 23:16:40 DEBUG nova.openstack.common.lockutils [req-6a569cb6-8802-45f3-bf8d-f446845bfdd1 demo demo] Got semaphore "compute_resources" for method "update_usage"... inner /opt/stack/nova/nova/openstack/common/lockutils.py:185 2012-11-20 23:16:40 DEBUG nova.openstack.common.lockutils [req-6a569cb6-8802-45f3-bf8d-f446845bfdd1 demo demo] Got semaphore "compute_resources" for method "update_usage"... inner /opt/stack/nova/nova/openstack/common/lockutils.py:185 2012-11-20 23:16:40 21855 ERROR nova.openstack.common.rpc.amqp [-] Exception during message handling 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last): 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 276, in _process_data 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp rval = self.proxy.dispatch(ctxt, version, method, **args) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/dispatcher.py", line 145, in dispatch 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/exception.py", line 115, in wrapped 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp temp_level, payload) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/exception.py", line 90, in wrapped 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp return f(*args, **kw) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 191, in decorated_function 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp pass 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 177, in decorated_function 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 218, in decorated_function 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp kwargs['instance']['uuid'], e, sys.exc_info()) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 206, in decorated_function 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 949, in run_instance 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp do_run_instance() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/lockutils.py", line 228, in inner 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp retval = f(*args, **kwargs) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 948, in do_run_instance 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp admin_password, is_first_time, instance) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 624, in _run_instance 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self._set_instance_error_state(context, instance['uuid']) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 612, in _run_instance 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp is_first_time, request_spec, filter_properties) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 643, in _reschedule_or_reraise 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self._deallocate_network(context, instance) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/compute/manager.py", line 883, in _deallocate_network 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.network_api.deallocate_for_instance(context, instance) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/network/api.py", line 211, in deallocate_for_instance 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.network_rpcapi.deallocate_for_instance(context, **args) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/network/rpcapi.py", line 148, in deallocate_for_instance 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp instance_id=instance_id, project_id=project_id, host=host)) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp return rpc.call(context, self._get_topic(topic), msg, timeout) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in call 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp return _get_impl().call(cfg.CONF, context, topic, msg, timeout) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in call 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp rpc_amqp.get_connection_pool(conf, Connection)) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 369, in call 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp rv = list(rv) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 330, in __iter__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.done() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 327, in __iter__ 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp self._iterator.next() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in iterconsume 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp yield self.ensure(_error_callback, _consume) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in ensure 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp error_callback(e) 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in _error_callback 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp raise rpc_common.Timeout() 2012-11-20 23:16:40 21855 TRACE nova.openstack.common.rpc.amqp Timeout: Timeout while waiting on RPC response.