[Openstack] Timeout during image build (task Networking)

Lillie Ross-CDSR11 Ross.Lillie at motorolasolutions.com
Mon Jun 18 22:03:57 UTC 2012


I'm receiving RPC timeouts when trying to launch an instance.  My installation is the Essex release running on Ubuntu 12.04.

When I launch a test image, the launch fails.  In my setup, Nova network runs on a controller node, and all compute instances run on separate, dedicated server nodes.  The failure is repeatable.  Upon examining the various logs, I see the following (see below).  Any insight would be welcome.

Regards,
Ross

>From 'nova show <instance name>' I read the following:

root at cirrus1:~# nova show test
+-------------------------------------+-----------------------------------------------------------------------------+
|               Property              |                                    Value                                    |
+-------------------------------------+-----------------------------------------------------------------------------+
| OS-DCF:diskConfig                   | MANUAL                                                                      |
| OS-EXT-SRV-ATTR:host                | nova8                                                                       |
| OS-EXT-SRV-ATTR:hypervisor_hostname | None                                                                        |
| OS-EXT-SRV-ATTR:instance_name       | instance-00000005                                                           |
| OS-EXT-STS:power_state              | 0                                                                           |
| OS-EXT-STS:task_state               | networking                                                                  |
| OS-EXT-STS:vm_state                 | error                                                                       |
| accessIPv4                          |                                                                             |
| accessIPv6                          |                                                                             |
| config_drive                        |                                                                             |
| created                             | 2012-06-18T20:42:56Z                                                        |
| fault                               | {u'message': u'Timeout', u'code': 500, u'created': u'2012-06-18T20:43:58Z'} |
| flavor                              | m1.tiny                                                                     |
| hostId                              | 50272989300483e2b5e5236cd572fef3f9149ae60faa5f5660f8da54                    |
| id                                  | d569b16f-10a8-4cb8-90a3-d5b664c2322d                                        |
| image                               | tty-linux                                                                   |
| key_name                            | admin                                                                       |
| metadata                            | {}                                                                          |
| name                                | test                                                                        |
| private_0 network                   |                                                                             |
| status                              | ERROR                                                                       |
| tenant_id                           | 1                                                                           |
| updated                             | 2012-06-18T20:43:57Z                                                        |
| user_id                             | 1                                                                           |
+-------------------------------------+-----------------------------------------------------------------------------+

>From the nova-network.log I see the following:

2012-06-18 15:43:36 DEBUG nova.manager [-] Running periodic task VlanManager._disassociate_stale_fixed_ips from (pid=1381) periodic_tasks /usr/lib/python2.7/dist-packages
/nova/manager.py:152
2012-06-18 15:43:57 ERROR nova.rpc.common [-] Timed out waiting for RPC response: timed out
2012-06-18 15:43:57 TRACE nova.rpc.common Traceback (most recent call last):
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 490, in ensure
2012-06-18 15:43:57 TRACE nova.rpc.common     return method(*args, **kwargs)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 567, in _consume
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.connection.drain_events(timeout=timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 175, in drain_events
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.transport.drain_events(self.connection, **kwargs)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 238, in drain_events
2012-06-18 15:43:57 TRACE nova.rpc.common     return connection.drain_events(**kwargs)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 57, in drain_events
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.wait_multi(self.channels.values(), timeout=timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 63, in wait_multi
2012-06-18 15:43:57 TRACE nova.rpc.common     chanmap.keys(), allowed_methods, timeout=timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 120, in _wait_multiple
2012-06-18 15:43:57 TRACE nova.rpc.common     channel, method_sig, args, content = read_timeout(timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 94, in read_timeout
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.method_reader.read_method()
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2012-06-18 15:43:57 TRACE nova.rpc.common     raise m
2012-06-18 15:43:57 TRACE nova.rpc.common timeout: timed out
2012-06-18 15:43:57 TRACE nova.rpc.common
2012-06-18 15:43:58 DEBUG nova.utils [req-16158a6b-f3d6-49f3-977e-3ccfecc791ca 1 1] Attempting to grab semaphore "get_dhcp" for method "_get_dhcp_ip"... from (pid=1381) i
nner /usr/lib/python2.7/dist-packages/nova/utils.py:927
2012-06-18 15:43:58 DEBUG nova.utils [req-16158a6b-f3d6-49f3-977e-3ccfecc791ca 1 1] Got semaphore "get_dhcp" for method "_get_dhcp_ip"... from (pid=1381) inner /usr/lib/p
ython2.7/dist-packages/nova/utils.py:931
2012-06-18 15:43:58 DEBUG nova.utils [req-16158a6b-f3d6-49f3-977e-3ccfecc791ca 1 1] Attempting to grab semaphore "get_dhcp" for method "_get_dhcp_ip"... from (pid=1381) i

and from nova-compute.log I read:

2012-06-18 15:43:57 ERROR nova.rpc.common [req-16158a6b-f3d6-49f3-977e-3ccfecc791ca 1 1] Timed out waiting for RPC response: timed out
2012-06-18 15:43:57 TRACE nova.rpc.common Traceback (most recent call last):
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 490, in ensure
2012-06-18 15:43:57 TRACE nova.rpc.common     return method(*args, **kwargs)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 567, in _consume
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.connection.drain_events(timeout=timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 175, in drain_events
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.transport.drain_events(self.connection, **kwargs)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 238, in drain_events
2012-06-18 15:43:57 TRACE nova.rpc.common     return connection.drain_events(**kwargs)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 57, in drain_events
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.wait_multi(self.channels.values(), timeout=timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 63, in wait_multi
2012-06-18 15:43:57 TRACE nova.rpc.common     chanmap.keys(), allowed_methods, timeout=timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 120, in _wait_multiple
2012-06-18 15:43:57 TRACE nova.rpc.common     channel, method_sig, args, content = read_timeout(timeout)
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 94, in read_timeout
2012-06-18 15:43:57 TRACE nova.rpc.common     return self.method_reader.read_method()
2012-06-18 15:43:57 TRACE nova.rpc.common   File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2012-06-18 15:43:57 TRACE nova.rpc.common     raise m
2012-06-18 15:43:57 TRACE nova.rpc.common timeout: timed out
2012-06-18 15:43:57 TRACE nova.rpc.common
2012-06-18 15:43:57 ERROR nova.compute.manager [req-16158a6b-f3d6-49f3-977e-3ccfecc791ca 1 1] [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d] Instance failed network setup
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d] Traceback (most recent call last):
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 559, in _allocate_network
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     requested_networks=requested_networks)
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 170, in allocate_for_instance
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     'args': args})
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/__init__.py", line 68, in call
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     return _get_impl().call(context, topic, msg, timeout)
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 674, in call
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     return rpc_amqp.call(context, topic, msg, timeout, Connection.pool)
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 338, in call
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     rv = list(rv)
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 299, in __iter__
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     self._iterator.next()
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 572, in iterconsume
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     yield self.ensure(_error_callback, _consume)
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 503, in ensure
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     error_callback(e)
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 553, in _error_callback
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]     raise rpc_common.Timeout()
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d] Timeout: Timeout while waiting on RPC response.
2012-06-18 15:43:57 TRACE nova.compute.manager [instance: d569b16f-10a8-4cb8-90a3-d5b664c2322d]
2012-06-18 15:43:58 ERROR nova.rpc.amqp [req-16158a6b-f3d6-49f3-977e-3ccfecc791ca 1 1] Exception during message handling
2012-06-18 15:43:58 TRACE nova.rpc.amqp Traceback (most recent call last):
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 252, in _process_data
2012-06-18 15:43:58 TRACE nova.rpc.amqp     rval = node_func(context=ctxt, **node_args)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 114, in wrapped
2012-06-18 15:43:58 TRACE nova.rpc.amqp     return f(*args, **kw)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 177, in decorated_function
2012-06-18 15:43:58 TRACE nova.rpc.amqp     sys.exc_info())
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-06-18 15:43:58 TRACE nova.rpc.amqp     self.gen.next()
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 171, in decorated_function
2012-06-18 15:43:58 TRACE nova.rpc.amqp     return function(self, context, instance_uuid, *args, **kwargs)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 651, in run_instance
2012-06-18 15:43:58 TRACE nova.rpc.amqp     do_run_instance()
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 945, in inner
2012-06-18 15:43:58 TRACE nova.rpc.amqp     retval = f(*args, **kwargs)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 650, in do_run_instance
2012-06-18 15:43:58 TRACE nova.rpc.amqp     self._run_instance(context, instance_uuid, **kwargs)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 451, in _run_instance
2012-06-18 15:43:58 TRACE nova.rpc.amqp     self._set_instance_error_state(context, instance_uuid)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-06-18 15:43:58 TRACE nova.rpc.amqp     self.gen.next()
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 424, in _run_instance
2012-06-18 15:43:58 TRACE nova.rpc.amqp     requested_networks)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 559, in _allocate_network
2012-06-18 15:43:58 TRACE nova.rpc.amqp     requested_networks=requested_networks)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 170, in allocate_for_instance
2012-06-18 15:43:58 TRACE nova.rpc.amqp     'args': args})
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/__init__.py", line 68, in call
2012-06-18 15:43:58 TRACE nova.rpc.amqp     return _get_impl().call(context, topic, msg, timeout)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 674, in call
2012-06-18 15:43:58 TRACE nova.rpc.amqp     return rpc_amqp.call(context, topic, msg, timeout, Connection.pool)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 338, in call
2012-06-18 15:43:58 TRACE nova.rpc.amqp     rv = list(rv)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 299, in __iter__
2012-06-18 15:43:58 TRACE nova.rpc.amqp     self._iterator.next()
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 572, in iterconsume
2012-06-18 15:43:58 TRACE nova.rpc.amqp     yield self.ensure(_error_callback, _consume)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 503, in ensure
2012-06-18 15:43:58 TRACE nova.rpc.amqp     error_callback(e)
2012-06-18 15:43:58 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 553, in _error_callback
2012-06-18 15:43:58 TRACE nova.rpc.amqp     raise rpc_common.Timeout()
2012-06-18 15:43:58 TRACE nova.rpc.amqp Timeout: Timeout while waiting on RPC response.
2012-06-18 15:43:58 TRACE nova.rpc.amqp
2012-06-18 15:44:05 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=13262) periodic_tasks /usr/lib/python2.7/dist-packages/nova/manager.py:152
2012-06-18 15:44:05 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=13262) _publish_service_capabilities /usr/lib/python2.7/dist-packages/nova/manager.py:203
2012-06-18 15:44:05 DEBUG nova.rpc.amqp [-] Making asynchronous fanout cast... from (pid=13262) fanout_cast /usr/lib/python2.7/dist-packages/nova/rpc/amqp.py:354
2012-06-18 15:44:05 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=13262) periodic_tasks /usr/lib/python2.7/dist-packages/nova/manager.py:152
2012-06-18 15:44:05 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 1 ticks left until next run from
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack/attachments/20120618/dee0ce99/attachment.html>


More information about the Openstack mailing list