Open Stack

Hi all,

We've been seeing a problem where we can boot instances when there's one
Neutron network configured, but not if a second is configured (even
though the instance isn't using that network!).

The symptom is an ERROR status in the dashboard, and a
"MessagingTimeout: Timed out waiting for reply to message ID ..."
traceback in the nova-api log file inside a "validate_networks" call.
There are no other errors in any of the other log files, and no evidence
of anything unusual at all in the Neutron log file, even down to DEBUG
level.

Deleting the second network clears the problem: instances boot
successfully again.  I've included the nova-api.log traceback below -
we're using OpenStack Juno.

Has anybody seen this before, or does anyone have any suggestions for
what a good next debugging step is?  We were thinking of writing some
additional log statements into Nova and Neutron around the network
creation and validation areas - does this sound sensible?

Thanks,
Matt

ERROR nova.api.openstack [req-5a656fd3-343d-4893-9dba-aa997c67fcef None] Caught error: Timed out waiting for a reply to message ID 8b361e0d97bc4bc2a5a48e6892071e74
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 124, in __call__
    return req.get_response(self.application)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
    application, catch_exc_info=False)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
    return resp(environ, start_response)
  File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token.py", line 748, in __call__
    return self._call_app(env, start_response)
  File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token.py", line 684, in _call_app
    return self._app(env, _fake_start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
    return resp(environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
    return resp(environ, start_response)
  File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
    response = self.app(environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
    return resp(environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
    resp = self.call_func(req, *args, **self.kwargs)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 910, in __call__
    content_type, body, accept)
  File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 975, in _process_stack
    action_result = self.dispatch(meth, request, action_args)
  File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 1059, in dispatch
    return method(req=request, **action_args)
  File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 958, in create
    check_server_group_quota=check_server_group_quota)
  File "/usr/lib/python2.7/site-packages/nova/hooks.py", line 131, in inner
    rv = f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 1457, in create
    check_server_group_quota=check_server_group_quota)
  File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 1079, in _create_instance
    max_count)
  File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 770, in _validate_and_build_base_options
    requested_networks, max_count)
  File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 479, in _check_requested_networks
    max_count)
  File "/usr/lib/python2.7/site-packages/nova/network/api.py", line 48, in wrapped
    return func(self, context, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/nova/network/api.py", line 404, in validate_networks
    requested_networks)
  File "/usr/lib/python2.7/site-packages/nova/network/rpcapi.py", line 245, in validate_networks
    return self.client.call(ctxt, 'validate_networks', networks=networks)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/client.py", line 389, in call
    return self.prepare().call(ctxt, method, **kwargs)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/client.py", line 152, in call
    retry=self.retry)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/transport.py", line 90, in _send
    timeout=timeout, retry=retry)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 408, in send
    retry=retry)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 397, in _send
    result = self._waiter.wait(msg_id, timeout)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 285, in wait
    reply, ending = self._poll_connection(msg_id, timeout)
  File "/usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 235, in _poll_connection
    % msg_id)
MessagingTimeout: Timed out waiting for a reply to message ID 8b361e0d97bc4bc2a5a48e6892071e74