Create instance fails with nova.rpc.amqp ImageNotAuthorized: Not authorized for image

Asked by Elvinas Piliponis

Week ago (or so) did an update to latest available Ubuntu packages (at that time), today did update to todays packages. I was unable to update keystone, so I have deleted keystone DB and recreated all users. I then updated user and tenant ID's in nova and glance DBs for correct user ID mapping. It might be that I might have forgot some place but I am unable to find any references to old ID's and Nova region (RegionOne changed to nova).

Now I am unable to start new instances due to image authentication issue (euca-****, glance and nova commands works perfectly so no general Keystone authentication problems). No errors on master node. Computing node does report the following traceback:

2012-04-11 15:25:00 TRACE nova.rpc.amqp Traceback (most recent call last):
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 252, in _process_data
2012-04-11 15:25:00 TRACE nova.rpc.amqp rval = node_func(context=ctxt, **node_args)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 114, in wrapped
2012-04-11 15:25:00 TRACE nova.rpc.amqp return f(*args, **kw)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 177, in decorated_function
2012-04-11 15:25:00 TRACE nova.rpc.amqp sys.exc_info())
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-04-11 15:25:00 TRACE nova.rpc.amqp self.gen.next()
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 171, in decorated_function
2012-04-11 15:25:00 TRACE nova.rpc.amqp return function(self, context, instance_uuid, *args, **kwargs)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 651, in run_instance
2012-04-11 15:25:00 TRACE nova.rpc.amqp do_run_instance()
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 945, in inner
2012-04-11 15:25:00 TRACE nova.rpc.amqp retval = f(*args, **kwargs)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 650, in do_run_instance
2012-04-11 15:25:00 TRACE nova.rpc.amqp self._run_instance(context, instance_uuid, **kwargs)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 451, in _run_instance
2012-04-11 15:25:00 TRACE nova.rpc.amqp self._set_instance_error_state(context, instance_uuid)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-04-11 15:25:00 TRACE nova.rpc.amqp self.gen.next()
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 420, in _run_instance
2012-04-11 15:25:00 TRACE nova.rpc.amqp image_meta = self._check_image_size(context, instance)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 498, in _check_image_size
2012-04-11 15:25:00 TRACE nova.rpc.amqp image_meta = _get_image_meta(context, instance['image_ref'])
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 184, in _get_image_meta
2012-04-11 15:25:00 TRACE nova.rpc.amqp return image_service.show(context, image_id)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 241, in show
2012-04-11 15:25:00 TRACE nova.rpc.amqp _reraise_translated_image_exception(image_id)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 239, in show
2012-04-11 15:25:00 TRACE nova.rpc.amqp image_id)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 145, in _call_retry
2012-04-11 15:25:00 TRACE nova.rpc.amqp return getattr(client, name)(*args, **kwargs)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/glance/client.py", line 101, in get_image_meta
2012-04-11 15:25:00 TRACE nova.rpc.amqp res = self.do_request("HEAD", "/images/%s" % image_id)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/glance/common/client.py", line 61, in wrapped
2012-04-11 15:25:00 TRACE nova.rpc.amqp return func(self, *args, **kwargs)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/glance/common/client.py", line 420, in do_request
2012-04-11 15:25:00 TRACE nova.rpc.amqp headers=headers)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/glance/common/client.py", line 75, in wrapped
2012-04-11 15:25:00 TRACE nova.rpc.amqp return func(self, method, url, body, headers)
2012-04-11 15:25:00 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/glance/common/client.py", line 534, in _do_request
2012-04-11 15:25:00 TRACE nova.rpc.amqp raise exception.NotAuthenticated(res.read())
2012-04-11 15:25:00 TRACE nova.rpc.amqp ImageNotAuthorized: Not authorized for image 33096949-3900-4df8-8201-93d465cb581d.
2012-04-11 15:25:00 TRACE nova.rpc.amqp

Image exists and can be retrieved (I have inserted a copy of the image via "glance add" ):
root@stack102:/etc/glance# glance index | grep RHEL
33096949-3900-4df8-8201-93d465cb581d RHEL 6.1 - test raw ovf 7759462400
384b6942-9d8e-4f21-b533-a853f2b99b26 RHEL 6.1 raw ovf 7759462400
root@stack102:/etc/glance#

I have traced issue down to the folowing: glance rejects request to get image due to authentication token is not passed to Glance.

I have checked and it seems to be valid behaviour:
curl http://stack102:9292/v1/images/33096949-3900-4df8-8201-93d465cb581d (HTTP 401)
curl -H "X-Auth-Token:0f5000a382b24d6caeae89954103c46c" http://stack102:9292/v1/images/33096949-3900-4df8-8201-93d465cb581d (getting image content to terminal)

But actual instance start also does NOT have authentication token, although it is provided to compute node. ACSII TCP dump on the compute node when starting an instance:
http://paste.openstack.org/show/12689/

Glance reports in logs something like:
2012-04-11 14:17:49 4066 DEBUG [glance.api.middleware.version_negotiation] Processing request: HEAD /v1/images/33096949-3900-4df8-8201-93d465cb581d Accept:
2012-04-11 14:17:49 4066 DEBUG [glance.api.middleware.version_negotiation] Matched versioned URI. Version: 1.0
2012-04-11 14:17:49 4066 DEBUG [keystone.middleware.auth_token] Authenticating user token
2012-04-11 14:17:49 4066 DEBUG [keystone.middleware.auth_token] Removing headers from request environment: X-Identity-Status,X-Tenant-Id,X-Tenant-Name,X-User-Id,X-User-Name,X-Roles,X-User,X-Tenant,X-Role
2012-04-11 14:17:49 4066 WARNING [keystone.middleware.auth_token] Unable to find authentication token in headers: {'SCRIPT_NAME': '/v1', 'webob.adhoc_attrs': {'response': <Response at 0x22c8a50 200 OK>}, 'REQUEST_METHOD': 'HEAD', 'PATH_INFO': '/images/33096949-3900-4df8-8201-93d465cb581d', 'SERVER_PROTOCOL': 'HTTP/1.0', 'eventlet.posthooks': [], 'SERVER_NAME': '192.168.0.6', 'REMOTE_ADDR': '192.168.0.4', 'eventlet.input': <eventlet.wsgi.Input object at 0x22c8790>, 'wsgi.url_scheme': 'http', 'api.major_version': 1, 'SERVER_PORT': '9292', 'api.minor_version': 0, 'wsgi.input': <eventlet.wsgi.Input object at 0x22c8790>, 'HTTP_HOST': 'stack102:9292', 'wsgi.multithread': True, 'wsgi.version': (1, 0), 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <open file '<stderr>', mode 'w' at 0x7f739b3c5270>, 'wsgi.multiprocess': False, 'CONTENT_TYPE': 'text/plain', 'HTTP_ACCEPT_ENCODING': 'identity'}
2012-04-11 14:17:49 4066 INFO [keystone.middleware.auth_token] Invalid user token - rejecting request

Question information

Language:
English Edit question
Status:
Solved
For:
OpenStack Compute (nova) Edit question
Assignee:
No assignee Edit question
Solved by:
Elvinas Piliponis
Solved:
Last query:
Last reply:
Revision history for this message
Elvinas Piliponis (elvinas-piliponis) said :
#1

Well, after almost two days of wondering why second cluster does not work I have found the culprit.

nova.conf was missing the following line:
---auth_strategy=keystone

Without ir nova-compute does not attempt to auth agaisnt Keystone and send auth token to Glance.

What is strange is that other functions (I can delete instances, start/stop, pause/resume) are not affected by this missing line.