[Openstack] RPC timeout in nova-compute
Sg Kylin
kylin7.sg at gmail.com
Mon Aug 5 12:49:02 UTC 2013
Is nova-conductor running?
On Monday, August 5, 2013, Jiaan Zeng wrote:
> OK. Below is the log snippet from nova-compute.log. It includes the
> steps of instance starts, throws network error and terminates. Any
> suggestions? Thanks a lot.
>
> 2013-08-05 02:55:18.104 AUDIT nova.compute.manager
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Starting instance...
> 2013-08-05 02:55:18.264 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Attempting claim:
> memory 2048 MB, disk 20 GB, VCPUs 1
> 2013-08-05 02:55:18.265 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Total Memory: 64354
> MB, used: 2560 MB
> 2013-08-05 02:55:18.265 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Memory limit: 96531
> MB, free: 93971 MB
> 2013-08-05 02:55:18.265 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Total Disk: 3179 GB,
> used: 20 GB
> 2013-08-05 02:55:18.266 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Disk limit not
> specified, defaulting to unlimited
> 2013-08-05 02:55:18.266 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Total CPU: 24 VCPUs,
> used: 1 VCPUs
> 2013-08-05 02:55:18.267 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] CPU limit not
> specified, defaulting to unlimited
> 2013-08-05 02:55:18.267 AUDIT nova.compute.claims
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Claim successful
> 2013-08-05 02:56:18.562 ERROR nova.compute.manager
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Instance failed
> network setup
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Traceback (most recent call
> last):
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1071,
> in _allocate_network
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3]
> security_groups=security_groups)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 89, in
> wrapped
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] return func(self, context,
> *args, **kwargs)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 46, in
> wrapper
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] res = f(self, context,
> *args, **kwargs)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 270, in
> allocate_for_instance
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] nw_info =
> self.network_rpcapi.allocate_for_instance(context, **args)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/network/rpcapi.py", line 171,
> in allocate_for_instance
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] topic=topic, version='1.9')
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/proxy.py",
> line 80, in call
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] return rpc.call(context,
> self._get_topic(topic), msg, timeout)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/__init__.py",
> line 140, in call
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] return
> _get_impl().call(CONF, context, topic, msg, timeout)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/impl_kombu.py",
> line 798, in call
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3]
> rpc_amqp.get_connection_pool(conf, Connection))
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py",
> line 612, in call
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] rv = list(rv)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py",
> line 554, in __iter__
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] self.done()
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] self.gen.next()
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py",
> line 551, in __iter__
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] self._iterator.next()
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/impl_kombu.py",
> line 648, in iterconsume
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] yield
> self.ensure(_error_callback, _consume)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/impl_kombu.py",
> line 566, in ensure
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] error_callback(e)
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/impl_kombu.py",
> line 629, in _error_callback
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] raise rpc_common.Timeout()
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Timeout: Timeout while waiting
> on RPC response.
> 2013-08-05 02:56:18.562 26899 TRACE nova.compute.manager [instance:
> 6dc76ef9-46d1-4a4d-8553-d68f01780fd3]
> 2013-08-05 02:56:18.632 AUDIT nova.compute.manager
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Terminating instance
> 2013-08-05 02:57:00.426 26899 AUDIT nova.compute.resource_tracker [-]
> Auditing locally available compute resources
> 2013-08-05 02:57:00.519 26899 AUDIT nova.compute.resource_tracker [-]
> Free ram (MB): 59746
> 2013-08-05 02:57:00.519 26899 AUDIT nova.compute.resource_tracker [-]
> Free disk (GB): 3139
> 2013-08-05 02:57:00.520 26899 AUDIT nova.compute.resource_tracker [-]
> Free VCPUS: 22
> 2013-08-05 02:57:00.570 26899 INFO nova.compute.resource_tracker [-]
> Compute_service record updated for 192.168.100.51
> 2013-08-05 02:57:00.598 26899 INFO nova.compute.manager [-] Updating host
> status
> 2013-08-05 02:57:18.642 ERROR nova.compute.manager
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c7
> 5] [instance: 6dc76ef9-46d1-4a4d-8553-d68f01780fd3] Error: ['Traceback
> (most recent call last):\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/compute/ma
> nager.py", line 831, in _run_instance\n requested_networks, macs,
> security_groups)\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/compute/manager.py",
> line 1075, in _allocate_network\n instance=instance)\n', ' File
> "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n
> self.gen.next()\n', ' Fil
> e "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 1071, in _allocate_network\n security_groups=security_groups)\n', '
> File "/usr/lib/pyt
> hon2.7/dist-packages/nova/network/api.py", line 89, in wrapped\n
> return func(self, context, *args, **kwargs)\n', ' File
> "/usr/lib/python2.7/dist-packages
> /nova/network/api.py", line 46, in wrapper\n res = f(self, context,
> *args, **kwargs)\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/network/api.py", l
> ine 270, in allocate_for_instance\n nw_info =
> self.network_rpcapi.allocate_for_instance(context, **args)\n', ' File
> "/usr/lib/python2.7/dist-packages/nov
> a/network/rpcapi.py", line 171, in allocate_for_instance\n
> topic=topic, version=\'1.9\')\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/openstack/comm
> on/rpc/proxy.py", line 80, in call\n return rpc.call(context,
> self._get_topic(topic), msg, timeout)\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/ope
> nstack/common/rpc/__init__.py", line 140, in call\n return
> _get_impl().call(CONF, context, topic, msg, timeout)\n', ' File
> "/usr/lib/python2.7/dist-packa
> ges/nova/openstack/common/rpc/impl_kombu.py", line 798, in call\n
> rpc_amqp.get_connection_pool(conf, Connection))\n', ' File
> "/usr/lib/python2.7/dist-pac
> kages/nova/openstack/common/rpc/amqp.py", line 612, in call\n rv =
> list(rv)\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.p
> y", line 554, in __iter__\n self.done()\n', ' File
> "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n
> self.gen.next()\n', ' File "/usr/lib/py
> thon2.7/dist-packages/nova/openstack/common/rpc/amqp.py", line 551, in
> __iter__\n self._iterator.next()\n', ' File
> "/usr/lib/python2.7/dist-packages/nova
> /openstack/common/rpc/impl_kombu.py", line 648, in iterconsume\n
> yield self.ensure(_error_callback, _consume)\n', ' File
> "/usr/lib/python2.7/dist-package
> s/nova/openstack/common/rpc/impl_kombu.py", line 566, in ensure\n
> error_callback(e)\n', ' File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rp
> c/impl_kombu.py", line 629, in _error_callback\n raise
> rpc_common.Timeout()\n', 'Timeout: Timeout while waiting on RPC
> response.\n']
> 2013-08-05 02:57:19.103 ERROR nova.openstack.common.rpc.amqp
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae6d71e046c75]
> Exception during message handling
> 2013-08-05 02:57:19.103 ERROR nova.openstack.common.rpc.amqp
> [req-d1259d1e-54ad-4b31-bd8b-7c05d3553d95
> 05ef1007e3724ae78711f279def4f9b1 a3a3c88ea583470a8f2ae
> 6d71e046c75] Exception during message handling
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> Traceback (most recent call last):
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py",
> line 430, in
> _process_data
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> rval = self.proxy.dispatch(ctxt, version, method, **args)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File
> "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/dispatcher.py",
> line 13
> 3, in dispatch
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> return getattr(proxyobj, method)(ctxt, **kwargs)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 117,
> in wrapped
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> temp_level, payload)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> self.gen.next()
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 94, in
> wrapped
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> return f(self, context, *args, **kw)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 209, in decorated_function
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp pass
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> self.gen.next()
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 195, in decorated_function
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> return function(self, context, *args, **kwargs)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 260, in decorated_function
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> function(self, context, *args, **kwargs)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 237, in decorated_function
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> e, sys.exc_info())
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> self.gen.next()
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 224, in decorated_function
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> return function(self, context, *args, **kwargs)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 1224, in run_instance
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> do_run_instance()
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py",
> line 242, in inner
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> retval = f(*args, **kwargs)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 1223, in do_run_instance
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> admin_password, is_first_time, node, instance)
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line
> 879, in _run_insta
> nce
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.common.rpc.amqp
> self._set_instance_error_state(context, instance['uuid'])
> 2013-08-05 02:57:19.103 26899 TRACE nova.openstack.co
>
> On Mon, Aug 5, 2013 at 6:15 AM, Somanchi Trinath-B39208
> <B39208 at freescale.com> wrote:
> > Can you post the exact error from the nova log...
> >
> > --
> > Trinath Somanchi - B39208
> > trinath.somanchi at freescale.com | extn: 4048
> >
> > -----Original Message-----
> > From: Jiaan Zeng [mailto:l.allen09 at gmail.com]
> > Sent: Monday, August 05, 2013 7:49 AM
> > To: openstack at lists.openstack.org
> > Subject: [Openstack] RPC timeout in nova-compute
> >
> > Hi,
> >
> > I have been struggling on setting up quantum with grizzly for a long
> time. From nova-compute.log, I can see there is a RPC timeout error from
> get_instance_nw_info() function in file /usr/lib/python2.7/dist-packages
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack/attachments/20130805/574df1dc/attachment.html>
More information about the Openstack
mailing list