yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #14034
[Bug 1314756] [NEW] Default RedHat Install of IceHouse fails
Public bug reported:
When following the deployment guide for RedHat IceHouse install the nova
compute layer fails to launch a vm via the dashboard.
I am running CentOs 6.4.
The resulting error from the api.log is:
2014-04-29 16:16:49.723 2252 ERROR nova.api.openstack [req-a5503226-ad62-47fd-9ce2-9bd0b3c79d54 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Caught error: Timed out waiting for a reply to message ID 1c8a38a6a601410981cc630ddefa6346
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack Traceback (most recent call last):
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return req.get_response(self.application)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/request.py", line 1296, in send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack application, catch_exc_info=False)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/request.py", line 1260, in call_application
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack app_iter = application(self.environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py", line 615, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.app(env, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py", line 131, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack response = self.app(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 130, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 195, in call_func
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.func(req, *args, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 917, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack content_type, body, accept)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 983, in _process_stack
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1070, in dispatch
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return method(req=request, **action_args)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/servers.py", line 956, in create
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack legacy_bdm=legacy_bdm)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/hooks.py", line 103, in inner
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack rv = f(*args, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 1341, in create
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack legacy_bdm=legacy_bdm)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 968, in _create_instance
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack max_count)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 739, in _validate_and_build_base_options
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack requested_networks, max_count)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 463, in _check_requested_networks
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack max_count)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 94, in wrapped
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return func(self, context, *args, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 419, in validate_networks
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack requested_networks)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/rpcapi.py", line 225, in validate_networks
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.client.call(ctxt, 'validate_networks', networks=networks)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/rpc/client.py", line 361, in call
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.prepare().call(ctxt, method, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/rpc/client.py", line 150, in call
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack wait_for_reply=True, timeout=timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/transport.py", line 90, in _send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack timeout=timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 412, in send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self._send(target, ctxt, message, wait_for_reply, timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 403, in _send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack result = self._waiter.wait(msg_id, timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 267, in wait
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack reply, ending = self._poll_connection(msg_id, timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 217, in _poll_connection
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack % msg_id)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack MessagingTimeout: Timed out waiting for a reply to message ID 1c8a38a6a601410981cc630ddefa6346
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack
Running nova in debug mode produces:
2014-04-30 09:45:06.403 2449 INFO nova.api.openstack [req-98a87c05-5b69-4a78-975c-a1870db5979b ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] http://nmtg-ctrl001:8774/v2/cc55e4c69e404fc4b89e2983a36efd80/servers returned with HTTP 500
2014-04-30 09:45:06.404 2449 DEBUG nova.api.openstack.wsgi [req-98a87c05-5b69-4a78-975c-a1870db5979b ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Returning 500 to user: The server has either erred or is incapable of performing the requested operation. __call__ /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:1215
2014-04-30 09:45:06.404 2449 INFO nova.osapi_compute.wsgi.server [req-98a87c05-5b69-4a78-975c-a1870db5979b ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "POST /v2/cc55e4c69e404fc4b89e2983a36efd80/servers HTTP/1.1" status: 500 len: 335 time: 60.1515419
2014-04-30 09:45:06.462 2449 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:45:06.462 2449 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:45:06.463 2449 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:1010
2014-04-30 09:45:06.463 2449 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ca8cf7879f304f328420a023aa47d821 with project_id : cc55e4c69e404fc4b89e2983a36efd80 and roles: admin,_member_ _build_user_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:909
2014-04-30 09:45:06.465 2449 DEBUG routes.middleware [-] Matched GET /cc55e4c69e404fc4b89e2983a36efd80/servers/detail __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:100
2014-04-30 09:45:06.465 2449 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0x4471610>} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:102
2014-04-30 09:45:06.465 2449 DEBUG routes.middleware [-] Match dict: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0x4471610>, 'project_id': u'cc55e4c69e404fc4b89e2983a36efd80'} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:103
2014-04-30 09:45:06.466 2449 DEBUG nova.api.openstack.wsgi [req-8cad30be-8cbd-4dd6-8439-3b87ba41066e ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Calling method '<bound method Controller.detail of <nova.api.openstack.compute.servers.Controller object at 0x446da10>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:945
2014-04-30 09:45:06.466 2449 DEBUG nova.compute.api [req-8cad30be-8cbd-4dd6-8439-3b87ba41066e ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Searching by: {'deleted': False, u'project_id': u'cc55e4c69e404fc4b89e2983a36efd80', u'limit': u'21'} get_all /usr/lib/python2.6/site-packages/nova/compute/api.py:1839
2014-04-30 09:45:06.489 2449 INFO nova.osapi_compute.wsgi.server [req-8cad30be-8cbd-4dd6-8439-3b87ba41066e ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "GET /v2/cc55e4c69e404fc4b89e2983a36efd80/servers/detail?limit=21&project_id=cc55e4c69e404fc4b89e2983a36efd80 HTTP/1.1" status: 200 len: 187 time: 0.0271010
2014-04-30 09:45:06.628 2449 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:45:06.628 2449 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:45:06.629 2449 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:1010
2014-04-30 09:45:06.629 2449 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ca8cf7879f304f328420a023aa47d821 with project_id : cc55e4c69e404fc4b89e2983a36efd80 and roles: admin,_member_ _build_user_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:909
2014-04-30 09:45:06.631 2449 DEBUG routes.middleware [-] Matched GET /cc55e4c69e404fc4b89e2983a36efd80/limits __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:100
2014-04-30 09:45:06.631 2449 DEBUG routes.middleware [-] Route path: '/{project_id}/limits', defaults: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:102
2014-04-30 09:45:06.631 2449 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>, 'project_id': u'cc55e4c69e404fc4b89e2983a36efd80'} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:103
2014-04-30 09:45:06.632 2449 DEBUG nova.api.openstack.wsgi [req-7bc99257-16fa-4a15-be25-05ec02e7d2e7 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Calling method '<bound method LimitsController.index of <nova.api.openstack.compute.limits.LimitsController object at 0x461bcd0>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:945
2014-04-30 09:45:06.641 2449 INFO nova.osapi_compute.wsgi.server [req-7bc99257-16fa-4a15-be25-05ec02e7d2e7 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "GET /v2/cc55e4c69e404fc4b89e2983a36efd80/limits?reserved=1 HTTP/1.1" status: 200 len: 604 time: 0.0136478
2014-04-30 09:45:06.647 2449 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:45:06.647 2449 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:45:06.648 2449 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:1010
2014-04-30 09:45:06.649 2449 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ca8cf7879f304f328420a023aa47d821 with project_id : cc55e4c69e404fc4b89e2983a36efd80 and roles: admin,_member_ _build_user_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:909
2014-04-30 09:45:06.650 2449 DEBUG routes.middleware [-] Matched GET /cc55e4c69e404fc4b89e2983a36efd80/limits __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:100
2014-04-30 09:45:06.650 2449 DEBUG routes.middleware [-] Route path: '/{project_id}/limits', defaults: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:102
2014-04-30 09:45:06.651 2449 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>, 'project_id': u'cc55e4c69e404fc4b89e2983a36efd80'} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:103
2014-04-30 09:45:06.651 2449 DEBUG nova.api.openstack.wsgi [req-2e11a8f1-5aa6-41b9-a424-e0ab27963d17 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Calling method '<bound method LimitsController.index of <nova.api.openstack.compute.limits.LimitsController object at 0x461bcd0>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:945
2014-04-30 09:45:06.660 2449 INFO nova.osapi_compute.wsgi.server [req-2e11a8f1-5aa6-41b9-a424-e0ab27963d17 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "GET /v2/cc55e4c69e404fc4b89e2983a36efd80/limits?reserved=1 HTTP/1.1" status: 200 len: 604 time: 0.0129499
2014-04-30 09:47:12.463 2445 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:47:12.463 2445 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:47:12.464 2445 WARNING keystoneclient.middleware.auth_token [-] Unable to find authentication token in headers
2014-04-30 09:47:12.464 2445 DEBUG keystoneclient.middleware.auth_token [-] Headers: {'SCRIPT_NAME': '/v2', 'webob.adhoc_attrs': {'response': <Response at 0x55b60d0 200 OK>}, 'REQUEST_METHOD': 'GET', 'PATH_INFO': '/cc55e4c69e404fc4b89e2983a36efd80/servers', 'SERVER_PROTOCOL': 'HTTP/1.0', 'HTTP_USER_AGENT': 'curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2', 'REMOTE_PORT': '32776', 'SERVER_NAME': '10.81.76.105', 'REMOTE_ADDR': '10.81.76.105', 'eventlet.input': <eventlet.wsgi.Input object at 0x55a8d50>, 'wsgi.url_scheme': 'http', 'SERVER_PORT': '8774', 'wsgi.input': <eventlet.wsgi.Input object at 0x55a8d50>, 'HTTP_HOST': 'nmtg-ctrl001:8774', 'nova.best_content_type': 'application/json', 'wsgi.multithread': True, 'eventlet.posthooks': [], 'HTTP_ACCEPT': '*/*', 'wsgi.version': (1, 0), 'RAW_PATH_INFO': '/v2/cc55e4c69e404fc4b89e2983a36efd80/servers', 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <open file '<stderr>', mode 'w' at 0x7f8c01c901e0>, 'wsgi.multiprocess': False, 'CONTENT_TYPE': 'text/plain'} _get_user_token_from_header /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:680
** Affects: nova
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1314756
Title:
Default RedHat Install of IceHouse fails
Status in OpenStack Compute (Nova):
New
Bug description:
When following the deployment guide for RedHat IceHouse install the
nova compute layer fails to launch a vm via the dashboard.
I am running CentOs 6.4.
The resulting error from the api.log is:
2014-04-29 16:16:49.723 2252 ERROR nova.api.openstack [req-a5503226-ad62-47fd-9ce2-9bd0b3c79d54 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Caught error: Timed out waiting for a reply to message ID 1c8a38a6a601410981cc630ddefa6346
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack Traceback (most recent call last):
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return req.get_response(self.application)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/request.py", line 1296, in send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack application, catch_exc_info=False)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/request.py", line 1260, in call_application
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack app_iter = application(self.environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py", line 615, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.app(env, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py", line 131, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack response = self.app(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return resp(environ, start_response)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 130, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 195, in call_func
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.func(req, *args, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 917, in __call__
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack content_type, body, accept)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 983, in _process_stack
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1070, in dispatch
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return method(req=request, **action_args)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/servers.py", line 956, in create
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack legacy_bdm=legacy_bdm)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/hooks.py", line 103, in inner
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack rv = f(*args, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 1341, in create
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack legacy_bdm=legacy_bdm)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 968, in _create_instance
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack max_count)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 739, in _validate_and_build_base_options
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack requested_networks, max_count)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 463, in _check_requested_networks
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack max_count)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 94, in wrapped
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return func(self, context, *args, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 419, in validate_networks
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack requested_networks)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/rpcapi.py", line 225, in validate_networks
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.client.call(ctxt, 'validate_networks', networks=networks)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/rpc/client.py", line 361, in call
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self.prepare().call(ctxt, method, **kwargs)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/rpc/client.py", line 150, in call
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack wait_for_reply=True, timeout=timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/transport.py", line 90, in _send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack timeout=timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 412, in send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack return self._send(target, ctxt, message, wait_for_reply, timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 403, in _send
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack result = self._waiter.wait(msg_id, timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 267, in wait
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack reply, ending = self._poll_connection(msg_id, timeout)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 217, in _poll_connection
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack % msg_id)
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack MessagingTimeout: Timed out waiting for a reply to message ID 1c8a38a6a601410981cc630ddefa6346
2014-04-29 16:16:49.723 2252 TRACE nova.api.openstack
Running nova in debug mode produces:
2014-04-30 09:45:06.403 2449 INFO nova.api.openstack [req-98a87c05-5b69-4a78-975c-a1870db5979b ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] http://nmtg-ctrl001:8774/v2/cc55e4c69e404fc4b89e2983a36efd80/servers returned with HTTP 500
2014-04-30 09:45:06.404 2449 DEBUG nova.api.openstack.wsgi [req-98a87c05-5b69-4a78-975c-a1870db5979b ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Returning 500 to user: The server has either erred or is incapable of performing the requested operation. __call__ /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:1215
2014-04-30 09:45:06.404 2449 INFO nova.osapi_compute.wsgi.server [req-98a87c05-5b69-4a78-975c-a1870db5979b ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "POST /v2/cc55e4c69e404fc4b89e2983a36efd80/servers HTTP/1.1" status: 500 len: 335 time: 60.1515419
2014-04-30 09:45:06.462 2449 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:45:06.462 2449 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:45:06.463 2449 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:1010
2014-04-30 09:45:06.463 2449 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ca8cf7879f304f328420a023aa47d821 with project_id : cc55e4c69e404fc4b89e2983a36efd80 and roles: admin,_member_ _build_user_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:909
2014-04-30 09:45:06.465 2449 DEBUG routes.middleware [-] Matched GET /cc55e4c69e404fc4b89e2983a36efd80/servers/detail __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:100
2014-04-30 09:45:06.465 2449 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0x4471610>} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:102
2014-04-30 09:45:06.465 2449 DEBUG routes.middleware [-] Match dict: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0x4471610>, 'project_id': u'cc55e4c69e404fc4b89e2983a36efd80'} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:103
2014-04-30 09:45:06.466 2449 DEBUG nova.api.openstack.wsgi [req-8cad30be-8cbd-4dd6-8439-3b87ba41066e ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Calling method '<bound method Controller.detail of <nova.api.openstack.compute.servers.Controller object at 0x446da10>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:945
2014-04-30 09:45:06.466 2449 DEBUG nova.compute.api [req-8cad30be-8cbd-4dd6-8439-3b87ba41066e ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Searching by: {'deleted': False, u'project_id': u'cc55e4c69e404fc4b89e2983a36efd80', u'limit': u'21'} get_all /usr/lib/python2.6/site-packages/nova/compute/api.py:1839
2014-04-30 09:45:06.489 2449 INFO nova.osapi_compute.wsgi.server [req-8cad30be-8cbd-4dd6-8439-3b87ba41066e ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "GET /v2/cc55e4c69e404fc4b89e2983a36efd80/servers/detail?limit=21&project_id=cc55e4c69e404fc4b89e2983a36efd80 HTTP/1.1" status: 200 len: 187 time: 0.0271010
2014-04-30 09:45:06.628 2449 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:45:06.628 2449 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:45:06.629 2449 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:1010
2014-04-30 09:45:06.629 2449 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ca8cf7879f304f328420a023aa47d821 with project_id : cc55e4c69e404fc4b89e2983a36efd80 and roles: admin,_member_ _build_user_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:909
2014-04-30 09:45:06.631 2449 DEBUG routes.middleware [-] Matched GET /cc55e4c69e404fc4b89e2983a36efd80/limits __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:100
2014-04-30 09:45:06.631 2449 DEBUG routes.middleware [-] Route path: '/{project_id}/limits', defaults: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:102
2014-04-30 09:45:06.631 2449 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>, 'project_id': u'cc55e4c69e404fc4b89e2983a36efd80'} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:103
2014-04-30 09:45:06.632 2449 DEBUG nova.api.openstack.wsgi [req-7bc99257-16fa-4a15-be25-05ec02e7d2e7 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Calling method '<bound method LimitsController.index of <nova.api.openstack.compute.limits.LimitsController object at 0x461bcd0>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:945
2014-04-30 09:45:06.641 2449 INFO nova.osapi_compute.wsgi.server [req-7bc99257-16fa-4a15-be25-05ec02e7d2e7 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "GET /v2/cc55e4c69e404fc4b89e2983a36efd80/limits?reserved=1 HTTP/1.1" status: 200 len: 604 time: 0.0136478
2014-04-30 09:45:06.647 2449 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:45:06.647 2449 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:45:06.648 2449 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:1010
2014-04-30 09:45:06.649 2449 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ca8cf7879f304f328420a023aa47d821 with project_id : cc55e4c69e404fc4b89e2983a36efd80 and roles: admin,_member_ _build_user_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:909
2014-04-30 09:45:06.650 2449 DEBUG routes.middleware [-] Matched GET /cc55e4c69e404fc4b89e2983a36efd80/limits __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:100
2014-04-30 09:45:06.650 2449 DEBUG routes.middleware [-] Route path: '/{project_id}/limits', defaults: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:102
2014-04-30 09:45:06.651 2449 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <nova.api.openstack.wsgi.Resource object at 0x461bd10>, 'project_id': u'cc55e4c69e404fc4b89e2983a36efd80'} __call__ /usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py:103
2014-04-30 09:45:06.651 2449 DEBUG nova.api.openstack.wsgi [req-2e11a8f1-5aa6-41b9-a424-e0ab27963d17 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] Calling method '<bound method LimitsController.index of <nova.api.openstack.compute.limits.LimitsController object at 0x461bcd0>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py:945
2014-04-30 09:45:06.660 2449 INFO nova.osapi_compute.wsgi.server [req-2e11a8f1-5aa6-41b9-a424-e0ab27963d17 ca8cf7879f304f328420a023aa47d821 cc55e4c69e404fc4b89e2983a36efd80] 10.81.76.105 "GET /v2/cc55e4c69e404fc4b89e2983a36efd80/limits?reserved=1 HTTP/1.1" status: 200 len: 604 time: 0.0129499
2014-04-30 09:47:12.463 2445 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:602
2014-04-30 09:47:12.463 2445 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:661
2014-04-30 09:47:12.464 2445 WARNING keystoneclient.middleware.auth_token [-] Unable to find authentication token in headers
2014-04-30 09:47:12.464 2445 DEBUG keystoneclient.middleware.auth_token [-] Headers: {'SCRIPT_NAME': '/v2', 'webob.adhoc_attrs': {'response': <Response at 0x55b60d0 200 OK>}, 'REQUEST_METHOD': 'GET', 'PATH_INFO': '/cc55e4c69e404fc4b89e2983a36efd80/servers', 'SERVER_PROTOCOL': 'HTTP/1.0', 'HTTP_USER_AGENT': 'curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2', 'REMOTE_PORT': '32776', 'SERVER_NAME': '10.81.76.105', 'REMOTE_ADDR': '10.81.76.105', 'eventlet.input': <eventlet.wsgi.Input object at 0x55a8d50>, 'wsgi.url_scheme': 'http', 'SERVER_PORT': '8774', 'wsgi.input': <eventlet.wsgi.Input object at 0x55a8d50>, 'HTTP_HOST': 'nmtg-ctrl001:8774', 'nova.best_content_type': 'application/json', 'wsgi.multithread': True, 'eventlet.posthooks': [], 'HTTP_ACCEPT': '*/*', 'wsgi.version': (1, 0), 'RAW_PATH_INFO': '/v2/cc55e4c69e404fc4b89e2983a36efd80/servers', 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <open file '<stderr>', mode 'w' at 0x7f8c01c901e0>, 'wsgi.multiprocess': False, 'CONTENT_TYPE': 'text/plain'} _get_user_token_from_header /usr/lib/python2.6/site-packages/keystoneclient/middleware/auth_token.py:680
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1314756/+subscriptions
Follow ups
References