Description of problem: When use api_servers in nova.conf with multiple glance api backends nova will retry for the next configured glance api backend if the 1st is down. This works for works-> boot Boot a new server. works-> image-create Create a new image by taking a snapshot of a works-> image-delete Delete specified image(s). works-> image-meta Set or Delete metadata on an image. works-> image-show Show details about the given image. But fails for image-list since the actual call is not being performed at the same place: fails-> image-list Print a list of available images to boot from. Version-Release number of selected component (if applicable): python-nova-2014.2.3-48.el7ost.noarch How reproducible: always when the glance api backend is being chosen Steps to Reproduce: 1. configure glance backend api servers in nova.conf api_servers=http://192.168.122.30:9292/v1,http://192.168.122.31:9292/v1 num_retries = 5 2. bring down one glance api 3. run nova image-list Actual results: nova image-list fails with: # nova image-list ERROR (ClientException): The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-5be8807d-7479-403b-87ad-80eae814c659) From log we see: 2016-02-29 11:06:09.681 13562 DEBUG nova.image.glance [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] maxretry: 6 call /usr/lib/python2.7/site-packages/nova/image/glance.py:231 2016-02-29 11:06:09.682 13562 DEBUG nova.image.glance [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] retry: 1 call /usr/lib/python2.7/site-packages/nova/image/glance.py:233 2016-02-29 11:06:09.682 13562 DEBUG nova.image.glance [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] create_onetime_client _create_onetime_client /usr/lib/python2.7/site-packages/nova/image/glance.py:213 2016-02-29 11:06:09.682 13562 DEBUG nova.image.glance [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] api_server None _create_onetime_client /usr/lib/python2.7/site-packages/nova/image/glance.py:214 2016-02-29 11:06:09.690 13562 DEBUG glanceclient.common.http [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 ] curl -i -X GET -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'User-Agent: python-glanceclient' -H 'Connection: keep-alive' -H 'X-Auth-Token: {SHA1}927f083df8e2b990f0fd9e11ffb847011f027805' -H 'Content-Type: application/octet-stream' http://192.168.122.31:9292/v1/images/detail?is_public=none&limit=20 log_curl_request /usr/lib/python2.7/site-packages/glanceclient/common/http.py:120 2016-02-29 11:06:09.692 13562 ERROR nova.api.openstack [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] Caught error: Error finding address for http://192.168.122.31:9292/v1/images/detail?is_public=none&limit=20: ('Connection aborted.', error(111, 'ECONNREFUSED')) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack Traceback (most recent call last): 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 124, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return req.get_response(self.application) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack application, catch_exc_info=False) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack app_iter = application(self.environ, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return resp(environ, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token.py", line 823, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return self._call_app(env, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token.py", line 758, in _call_app 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return self._app(env, _fake_start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return resp(environ, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return resp(environ, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack response = self.app(environ, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return resp(environ, start_response) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return self.func(req, *args, **kwargs) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 910, in __call__ 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack content_type, body, accept) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 975, in _process_stack 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 1059, in dispatch 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return method(req=request, **action_args) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/images.py", line 196, in detail 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack **page_params) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/image/api.py", line 68, in get_all 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return session.detail(context, **kwargs) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 292, in detail 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack for image in images: 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/glanceclient/v1/images.py", line 196, in paginate 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack images, resp = self._list(url, "images") 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/glanceclient/v1/images.py", line 62, in _list 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack resp, body = self.client.get(url) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 253, in get 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack return self._request('GET', url, **kwargs) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 208, in _request 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack raise exc.CommunicationError(message=message) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack CommunicationError: Error finding address for http://192.168.122.31:9292/v1/images/detail?is_public=none&limit=20: ('Connection aborted.', error(111, 'ECONNREFUSED')) 2016-02-29 11:06:09.692 13562 TRACE nova.api.openstack 2016-02-29 11:06:09.695 13562 INFO nova.api.openstack [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] http://192.168.122.30:8774/v2/9ba4055a7ccf437e88ad38e8b1b4b9cd/images/detail returned with HTTP 500 2016-02-29 11:06:09.696 13562 DEBUG nova.api.openstack.wsgi [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] Returning 500 to user: The server has either erred or is incapable of performing the requested operation. __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:1201 2016-02-29 11:06:09.696 13562 INFO nova.osapi_compute.wsgi.server [req-f0d9b163-7594-4ec2-b2ef-048f73a1a405 None] 192.168.122.30 "GET /v2/9ba4055a7ccf437e88ad38e8b1b4b9cd/images/detail HTTP/1.1" status: 500 len: 359 time: 0.7263141 Expected results: Retry to the next glance api server from the nova configuration as we see it for e.g. delete: - image-delete 2016-02-29 09:56:27.025 31401 DEBUG glanceclient.common.http [req-0825cffd-9d92-4d1f-9671-52a71df11dab ] curl -i -X DELETE -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'User-Agent: python-glanceclient' -H 'Connection: keep-alive' -H 'X-Auth-Token: {SHA1}91d753617f322b1a4e2b08878fd4c4a3f0a62c70' -H 'Content-Type: application/octet-stream' http://192.168.122.31:9292/v1/images/9a9351cb-7955-4c21-880b-9e96bd7465f8 log_curl_request /usr/lib/python2.7/site-packages/glanceclient/common/http.py:120 2016-02-29 09:56:27.026 31401 ERROR nova.image.glance [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] Error contacting glance server '192.168.122.31:9292' for 'delete', retrying. 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance Traceback (most recent call last): 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 240, in call 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance _getattr = getattr(client.images, method)(*args, **kwargs) 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance File "/usr/lib/python2.7/site-packages/glanceclient/v1/images.py", line 255, in delete 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance resp, body = self.client.delete(url) 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 265, in delete 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance return self._request('DELETE', url, **kwargs) 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 208, in _request 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance raise exc.CommunicationError(message=message) 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance CommunicationError: Error finding address for http://192.168.122.31:9292/v1/images/9a9351cb-7955-4c21-880b-9e96bd7465f8: ('Connection aborted.', error(111, 'ECONNREFUSED')) 2016-02-29 09:56:27.026 31401 TRACE nova.image.glance 2016-02-29 09:56:28.027 31401 DEBUG nova.image.glance [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] retry: 2 call /usr/lib/python2.7/site-packages/nova/image/glance.py:233 2016-02-29 09:56:28.028 31401 DEBUG nova.image.glance [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] create_onetime_client _create_onetime_client /usr/lib/python2.7/site-packages/nova/image/glance.py:213 2016-02-29 09:56:28.028 31401 DEBUG nova.image.glance [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] api_server <itertools.cycle object at 0x53ac440> _create_onetime_client /usr/lib/python2.7/site-packages/nova/image/glance.py:214 2016-02-29 09:56:28.029 31401 DEBUG nova.image.glance [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] GETATTR call /usr/lib/python2.7/site-packages/nova/image/glance.py:237 2016-02-29 09:56:28.030 31401 DEBUG glanceclient.common.http [req-0825cffd-9d92-4d1f-9671-52a71df11dab ] curl -i -X DELETE -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'User-Agent: python-glanceclient' -H 'Connection: keep-alive' -H 'X-Auth-Token: {SHA1}91d753617f322b1a4e2b08878fd4c4a3f0a62c70' -H 'Content-Type: application/octet-stream' http://192.168.122.30:9292/v1/images/9a9351cb-7955-4c21-880b-9e96bd7465f8 log_curl_request /usr/lib/python2.7/site-packages/glanceclient/common/http.py:120 2016-02-29 09:56:31.109 31401 DEBUG glanceclient.common.http [req-0825cffd-9d92-4d1f-9671-52a71df11dab ] HTTP/1.1 200 OK date: Mon, 29 Feb 2016 14:56:31 GMT connection: keep-alive content-type: text/html; charset=UTF-8 content-length: 0 x-openstack-request-id: req-922a12e8-316a-4fb3-b55f-30a9dc8c55be log_http_response /usr/lib/python2.7/site-packages/glanceclient/common/http.py:133 2016-02-29 09:56:31.110 31401 DEBUG nova.image.glance [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] AFTER GETATTR call /usr/lib/python2.7/site-packages/nova/image/glance.py:241 2016-02-29 09:56:31.111 31401 INFO nova.osapi_compute.wsgi.server [req-0825cffd-9d92-4d1f-9671-52a71df11dab None] 192.168.122.30 "DELETE /v2/9ba4055a7ccf437e88ad38e8b1b4b9cd/images/9a9351cb-7955-4c21-880b-9e96bd7465f8 HTTP/1.1" status: 204 len: 211 time: 4.0928562 Additional info:
/usr/lib/python2.7/site-packages/nova/image/glance.py 283 def detail(self, context, **kwargs): 284 """Calls out to Glance for a list of detailed image information.""" 285 params = _extract_query_params(kwargs) 286 try: ** actual client call --> 287 images = self._client.call(context, 1, 'list', **params) 288 except Exception: 289 _reraise_translated_exception() 290 291 _images = [] ** here we fail from the trace --> 292 for image in images: 293 if _is_image_available(context, image): 294 _images.append(_translate_from_glance(image)) 295 296 return _images We should already fail in call: 222 def call(self, context, version, method, *args, **kwargs): 223 """Call a glance client method. If we get a connection error, 224 retry the request according to CONF.glance.num_retries. 225 """ exceptions which lead to a retry --> 226 retry_excs = (glanceclient.exc.ServiceUnavailable, 227 glanceclient.exc.InvalidEndpoint, 228 glanceclient.exc.CommunicationError) 229 num_attempts = 1 + CONF.glance.num_retries 230 231 LOG.debug("maxretry: %r", num_attempts) 232 for attempt in xrange(1, num_attempts + 1): 233 LOG.debug("retry: %r", attempt) 234 client = self.client or self._create_onetime_client(context, 235 version) 236 try: 237 return getattr(client.images, method)(*args, **kwargs) 238 except retry_excs as e: 239 host = self.host 240 port = self.port 241 242 if attempt < num_attempts: 243 extra = "retrying" 244 else: 245 extra = 'done trying' 246 247 error_msg = (_("Error contacting glance server " 248 "'%(host)s:%(port)s' for '%(method)s', " 249 "%(extra)s.") % 250 {'host': host, 'port': port, 251 'method': method, 'extra': extra}) 252 LOG.exception(error_msg) 253 if attempt == num_attempts: 254 raise exception.GlanceConnectionFailed( 255 host=host, port=port, reason=six.text_type(e)) 256 time.sleep(1)
This is indeed a bug, and it looks like it's been there for years. I'm surprised that I can't find an upstream bug report for it – I'll add one tomorrow. Quick summary in the mean time: In the case of 'nova image-list', glanceclient returns a python generator rather than an actual list of images. https://github.com/openstack/python-glanceclient/blob/d59e341a4cd99a8488d5cf41052d9b218379ac87/glanceclient/v1/images.py#L268 Because a generator is returned, an exception will never be raised here, so the retry mechanism is never executed. https://github.com/openstack/nova/blob/83261f3106a8bdde38d258a74da777add4956290/nova/image/glance.py#L249
Update: A fix for this bug has landed in upstream Nova master (Newton/OSP10). https://review.openstack.org/#/c/293127/ I have also proposed upstream backport patches for Nova Liberty/OSP8 & Mitaka/OSP9. https://review.openstack.org/#/c/295324/ https://review.openstack.org/#/c/295319/ This will likely not be backported to OSP6 and OSP7. Workarounds to consider instead: 1) glance image-list: http://docs.openstack.org/user-guide/common/cli_manage_images.html http://docs.openstack.org/openstack-ops/content/user_facing_images.html http://docs.openstack.org/cli-reference/glance.html 2) glance public_endpoint: http://docs.openstack.org/developer/glance/configuring.html#configuring-glance-public-endpoint
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2016-0694.html