[Bug 1473022] Re: Openstack Kilo :Nova-api fails to call compute node

Eric Duggan eric.duggan at solnetsolutions.co.nz
Thu Aug 6 01:27:46 UTC 2015 

I am also seeing this intermittently when running nova commands via the
command line on Centos 7.1

For example when running nova --debug list:

DEBUG (session:195) REQ: curl -g -i -X GET https://x.x.x.x:35357/v2.0 -H "Accept: application/json" -H "User-Agent: python-keystoneclient"
INFO (connectionpool:735) Starting new HTTPS connection (1): x.x.x.x
DEBUG (connectionpool:383) "GET /v2.0 HTTP/1.1" 200 347
DEBUG (session:224) RESP: [200] content-length: 347 set-cookie: node=mgmt03; path=/ vary: X-Auth-Token server: Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips mod_wsgi/3.4 Python/2.7.5 date: Thu, 06 Aug 2015 01:08:21 GMT content-type: application/json x-openstack-request-id: req-73b79363-f7b8-4a97-a8a7-f96c93c41f18
RESP BODY: {"version": {"status": "stable", "updated": "2014-04-17T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v2.0+json"}], "id": "v2.0", "links": [{"href": "https://x.x.x.x:35357/v2.0/", "rel": "self"}, {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}]}}

DEBUG (v2:76) Making authentication request to https://x.x.x.x:35357/v2.0/tokens
DEBUG (connectionpool:383) "POST /v2.0/tokens HTTP/1.1" 200 2727
DEBUG (iso8601:184) Parsed 2015-08-06T02:08:21Z into {'tz_sign': None, 'second_fraction': None, 'hour': u'02', 'daydash': u'06', 'tz_hour': None, 'month': None, 'timezone': u'Z', 'second': u'21', 'tz_minute': None, 'year': u'2015', 'separator': u'T', 'monthdash': u'08', 'day': None, 'minute': u'08'} with default timezone <iso8601.iso8601.Utc object at 0x1075cd0>
DEBUG (iso8601:140) Got u'2015' for 'year' with default None
DEBUG (iso8601:140) Got u'08' for 'monthdash' with default 1
DEBUG (iso8601:140) Got 8 for 'month' with default 8
DEBUG (iso8601:140) Got u'06' for 'daydash' with default 1
DEBUG (iso8601:140) Got 6 for 'day' with default 6
DEBUG (iso8601:140) Got u'02' for 'hour' with default None
DEBUG (iso8601:140) Got u'08' for 'minute' with default None
DEBUG (iso8601:140) Got u'21' for 'second' with default None
DEBUG (session:195) REQ: curl -g -i -X GET https://x.x.x.x:8774/v2/7c289b706e644980ac5b9a36874cdeff/servers/detail -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}618596dc30335e9c814b1daf459b81ce99431e91"
INFO (connectionpool:735) Starting new HTTPS connection (1): x.x.x.x
DEBUG (connectionpool:383) "GET /v2/7c289b706e644980ac5b9a36874cdeff/servers/detail HTTP/1.1" 401 23
DEBUG (session:224) RESP:
DEBUG (v2:76) Making authentication request to https://x.x.x.x:35357/v2.0/tokens
DEBUG (connectionpool:383) "POST /v2.0/tokens HTTP/1.1" 200 2727
DEBUG (connectionpool:383) "GET /v2/7c289b706e644980ac5b9a36874cdeff/servers/detail HTTP/1.1" 500 128
DEBUG (session:224) RESP:
DEBUG (shell:914) The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-a2b6989f-19b8-453e-bf93-34fa50a108e2)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/novaclient/shell.py", line 911, in main
    OpenStackComputeShell().main(argv)
  File "/usr/lib/python2.7/site-packages/novaclient/shell.py", line 838, in main
    args.func(self.cs, args)
  File "/usr/lib/python2.7/site-packages/novaclient/v2/shell.py", line 1377, in do_list
    sort_dirs=sort_dirs)
  File "/usr/lib/python2.7/site-packages/novaclient/v2/servers.py", line 583, in list
    return self._list("/servers%s%s" % (detail, query_string), "servers")
  File "/usr/lib/python2.7/site-packages/novaclient/base.py", line 64, in _list
    _resp, body = self.api.client.get(url)
  File "/usr/lib/python2.7/site-packages/keystoneclient/adapter.py", line 170, in get
    return self.request(url, 'GET', **kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 96, in request
    raise exceptions.from_response(resp, body, url, method)
ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-a2b6989f-19b8-453e-bf93-34fa50a108e2)

on the mgmt03 node in /var/log/nova/nova-api.log I see:

2015-08-06 13:08:22.890 7373 DEBUG keystoneclient.session [req-a2b6989f-19b8-453e-bf93-34fa50a108e2 03d24899e1d24a22bc1fae13dcc62fee 7c289b706e644980ac5b9a36874cdeff - - -] REQ: curl -g -i -X GET https://x.x.x.x:9696/v2.0/ports.json?device_id=a5a4cfd3-8ca0-4e93-9c6b-2fb02b73f9c5&device_id=54d1d328-fef7-40a1-9311-eadc204bbfe5&device_id=6d4f76d6-4362-402a-b369-c69d7154f671 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c114cb664ce090f96baf5cfeb8096690b480eb38" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:195
2015-08-06 13:08:22.894 7373 ERROR nova.api.openstack [req-a2b6989f-19b8-453e-bf93-34fa50a108e2 03d24899e1d24a22bc1fae13dcc62fee 7c289b706e644980ac5b9a36874cdeff - - -] Caught error: []
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack Traceback (most recent call last):
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return req.get_response(self.application)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     application, catch_exc_info=False)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return resp(environ, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 634, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return self._call_app(env, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 554, in _call_app
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return self._app(env, _fake_start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return resp(environ, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return resp(environ, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     response = self.app(environ, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return resp(environ, start_response)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 756, in __call__
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     content_type, body, accept)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 847, in _process_stack
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     request, action_args)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 710, in post_process_extensions
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     **action_args)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/contrib/security_groups.py", line 471, in detail
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     self._extend_servers(req, list(resp_obj.obj['servers']))
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/contrib/security_groups.py", line 422, in _extend_servers
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     servers))
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/network/security_group/neutron_driver.py", line 353, in get_instances_security_groups_bindings
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     ports = self._get_ports_from_server_list(servers, neutron)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/network/security_group/neutron_driver.py", line 312, in _get_ports_from_server_list
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     ports.extend(neutron.list_ports(**search_opts).get('ports'))
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 102, in with_params
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     ret = self.function(instance, *args, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 534, in list_ports
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     **_params)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 307, in list
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     for r in self._pagination(collection, path, **params):
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 320, in _pagination
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     res = self.get(path, params=params)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 293, in get
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     headers=headers, params=params)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 270, in retry_request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     headers=headers, params=params)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 200, in do_request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     content_type=self.content_type())
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/client.py", line 306, in do_request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return self.request(url, method, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/client.py", line 294, in request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     resp = super(SessionClient, self).request(*args, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystoneclient/adapter.py", line 95, in request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return self.session.request(url, method, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystoneclient/utils.py", line 318, in inner
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return func(*args, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 382, in request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     resp = send(**kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 416, in _send_request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     resp = self.session.request(method, url, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 465, in request
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     resp = self.send(prep, **send_kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 573, in send
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     r = adapter.send(request, **kwargs)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/requests/adapters.py", line 370, in send
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     timeout=timeout
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py", line 533, in urlopen
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     conn = self._get_conn(timeout=pool_timeout)
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py", line 239, in _get_conn
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     conn.close()
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib64/python2.7/httplib.py", line 780, in close
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     self.sock.close()   # close it manually... there may be other refs
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/requests/packages/urllib3/contrib/pyopenssl.py", line 213, in close
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack     return self.connection.shutdown()
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack Error: []
2015-08-06 13:08:22.894 7373 TRACE nova.api.openstack
2015-08-06 13:08:22.912 7373 INFO nova.api.openstack [req-a2b6989f-19b8-453e-bf93-34fa50a108e2 03d24899e1d24a22bc1fae13dcc62fee 7c289b706e644980ac5b9a36874cdeff - - -] http://x.x.x.x:8774/v2/7c289b706e644980ac5b9a36874cdeff/servers/detail returned with HTTP 500

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to python-novaclient in Ubuntu.
https://bugs.launchpad.net/bugs/1473022

Title:
  Openstack Kilo :Nova-api fails to call compute node

Status in Fuel for OpenStack:
  Incomplete
Status in python-novaclient package in Ubuntu:
  Incomplete

Bug description:
  DEBUG (session:195) REQ: curl -g -i -X POST http://x.x.x.x:8774/v2/b291d93fa0db49e98de4073085925475/servers -H "User-Agent: python-novaclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c86db8535580094e25d93dd3d33f6621396c76d5" -d '{"server": {"name": "demo-instance", "imageRef": "736526ba-1959-4788-9e50-c8ee44a435d9", "key_name": "test-key", "flavorRef": "2", "max_count": 1, "min_count": 1, "networks": [{"uuid": "7c204797-9da8-40fa-9dc0-2ee7dd0a2981"}], "security_groups": [{"name": "default"}]}}'
  DEBUG (connectionpool:362) "POST /v2/b291d93fa0db49e98de4073085925475/servers HTTP/1.1" 500 128
  DEBUG (session:223) RESP:
  DEBUG (shell:914) The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-d72b72e4-ade5-4b36-bd41-790862349ad4)
  Traceback (most recent call last):
    File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 911, in main
      OpenStackComputeShell().main(argv)
    File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 838, in main
      args.func(self.cs, args)
    File "/usr/lib/python2.7/dist-packages/novaclient/v2/shell.py", line 500, in do_boot
      server = cs.servers.create(*boot_args, **boot_kwargs)
    File "/usr/lib/python2.7/dist-packages/novaclient/v2/servers.py", line 929, in create
      **boot_kwargs)
    File "/usr/lib/python2.7/dist-packages/novaclient/v2/servers.py", line 557, in _boot
      return_raw=return_raw, **kwargs)
    File "/usr/lib/python2.7/dist-packages/novaclient/base.py", line 152, in _create
      _resp, body = self.api.client.post(url, body=body)
    File "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py", line 170, in post
      return self.request(url, 'POST', **kwargs)
    File "/usr/lib/python2.7/dist-packages/novaclient/client.py", line 96, in request
      raise exceptions.from_response(resp, body, url, method)
  ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-d72b72e4-ade5-4b36-bd41-790862349ad4)
  ERROR (ClientException): The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-d72b72e4-ade5-4b36-bd41-790862349ad4)

To manage notifications about this bug go to:
https://bugs.launchpad.net/fuel/+bug/1473022/+subscriptions

More information about the Ubuntu-openstack-bugs mailing list