Attaching volume fails with cinderclient.exceptions.Unauthorized

[gadLinux]

I'm testing my installation with Ubuntu 19.10 fully patched to the current date.

When I issue a volume attach it always fail:

> openstack server add volume eacae4f5-19b6-4ab4-81b4-7c05b8395af9 32215fb1-65fb-409e-96e0-6c819bec7809

I'm using admin and project level user credentials. Both lead to the same failure.

Client log can be seen in attached file: openstack-client-log.log

A little bit after the failure I get this on the keystone log:

2020-02-23 20:51:56.058017 2020-02-23 20:51:56.055 5475 WARNING keystone.server.flask.application [req-b36af07b-4ab6-47ea-a67e-499c9771425c 9a412bfbbf604ba68b40d8d26216007c 50d6766b28324b398c6b53ee8516f6f5 - default default] Could not recognize Fernet token: keystone.exception.TokenNotFound: Could not recognize Fernet token\x1b[00m

Something that seems strange but can lead to the unauthorized. There's no errors logged.

Nova and all other subsystems went right until the reported error.

2020-02-23 21:11:05.279 3917 DEBUG nova.api.openstack.wsgi [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] Action: 'create', calling method: <bound method VolumeAttachmentController.create of <nova.api.openstack.compute.volumes.VolumeAttachmentController object at 0x7faad0fdc450>>, body: {"volumeAttachment": {"volumeId": "32215fb1-65fb-409e-96e0-6c819bec7809"}} _process_stack /usr/lib/python3/dist-packages/nova/api/openstack/wsgi.py:520
2020-02-23 21:11:05.283 3917 DEBUG nova.compute.api [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] [instance: eacae4f5-19b6-4ab4-81b4-7c05b8395af9] Fetching instance by UUID get /usr/lib/python3/dist-packages/nova/compute/api.py:2600
2020-02-23 21:11:05.293 3917 DEBUG oslo_concurrency.lockutils [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] Lock "62ba656c-cf27-4dd2-8c01-a19cdf55b3bf" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py:327
2020-02-23 21:11:05.293 3917 DEBUG oslo_concurrency.lockutils [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] Lock "62ba656c-cf27-4dd2-8c01-a19cdf55b3bf" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py:339
2020-02-23 21:11:05.294 3917 DEBUG oslo_concurrency.lockutils [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] Lock "62ba656c-cf27-4dd2-8c01-a19cdf55b3bf" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py:327
2020-02-23 21:11:05.294 3917 DEBUG oslo_concurrency.lockutils [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] Lock "62ba656c-cf27-4dd2-8c01-a19cdf55b3bf" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.000s inner /usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py:339
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] Unexpected exception in API method: cinderclient.exceptions.Unauthorized: The request you have made requires authentication. (HTTP 401)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi Traceback (most recent call last):
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/openstack/wsgi.py", line 671, in wrapped
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return f(*args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/validation/__init__.py", line 110, in wrapper
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/validation/__init__.py", line 110, in wrapper
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/validation/__init__.py", line 110, in wrapper
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/openstack/compute/volumes.py", line 357, in create
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi delete_on_termination=delete_on_termination)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/compute/api.py", line 204, in inner
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return function(self, context, instance, *args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/compute/api.py", line 152, in inner
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return f(self, context, instance, *args, **kw)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/compute/api.py", line 4200, in attach_volume
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi volume = self.volume_api.get(context, volume_id)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/volume/cinder.py", line 397, in wrapper
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi res = method(self, ctx, *args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/volume/cinder.py", line 433, in wrapper
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi res = method(self, ctx, volume_id, *args, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/volume/cinder.py", line 500, in get
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi context, microversion=microversion).volumes.get(volume_id)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/cinderclient/v2/volumes.py", line 281, in get
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return self._get("/volumes/%s" % volume_id, "volume")
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/cinderclient/base.py", line 293, in _get
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi resp, body = self.api.client.get(url)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/cinderclient/client.py", line 214, in get
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return self._cs_request(url, 'GET', **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/cinderclient/client.py", line 205, in _cs_request
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi return self.request(url, method, **kwargs)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/cinderclient/client.py", line 191, in request
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi raise exceptions.from_response(resp, body)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi cinderclient.exceptions.Unauthorized: The request you have made requires authentication. (HTTP 401)
2020-02-23 21:11:22.366 3917 ERROR nova.api.openstack.wsgi
2020-02-23 21:11:22.379 3917 INFO nova.api.openstack.wsgi [req-f1d416d1-d40a-460b-9c6c-de25ba685228 9a68d670be6f454a92b36896f6424b5d 2ac35a13fbae41768400a2aa5cdf9594 - default default] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'cinderclient.exceptions.Unauthorized'>

I'm unable to identify exactly the version is run on ubuntu, because openstack --version reports 4.0.0 but library on nova api is:

ova-api:
  Installed: 2:20.0.1-0ubuntu1
  Candidate: 2:20.0.1-0ubuntu1
  Version table:
 *** 2:20.0.1-0ubuntu1 500
        500 http://archive.ubuntu.com/ubuntu eoan-updates/main amd64 Packages
        100 /var/lib/dpkg/status
     2:20.0.0-0ubuntu1 500
        500 http://archive.ubuntu.com/ubuntu eoan/main amd64 Packages

That seems to be for rocky.

My upgrade to rocky went no right so it's possible that I left something wrongly configured out there. But I cannot pinpoint where the error can be.

Is this a bug or configuration problem?

Best regards,

[gadLinux (gad-aguilardelgado)]

Openstack client log in debug mode

[gadLinux (gad-aguilardelgado)]

I made more investigations. Nova API against cinder API seems to be working well. The attach command fails:

> nova --os-project-name level2 volume-attach eacae4f5-19b6-4ab4-81b4-7c05b8395af9 32215fb1-65fb-409e-96e0-6c819bec7809

With:

2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi [req-6bbe7e03-8d57-4c15-9505-8973484a2a19 9a68d670be6f454a92b36896f6424b5d c010bd7c02174062bb1df9c9cc9e6c15 - default default] Unexpected exception in API method: cinderclient.exceptions.Unauthorized: The request you have made requires authentication. (HTTP 401)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi Traceback (most recent call last):
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/openstack/wsgi.py", line 671, in wrapped
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi return f(*args, **kwargs)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/validation/__init__.py", line 110, in wrapper
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/validation/__init__.py", line 110, in wrapper
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/validation/__init__.py", line 110, in wrapper
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/api/openstack/compute/volumes.py", line 357, in create
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi delete_on_termination=delete_on_termination)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/compute/api.py", line 204, in inner
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi return function(self, context, instance, *args, **kwargs)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/compute/api.py", line 152, in inner
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi return f(self, context, instance, *args, **kw)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/compute/api.py", line 4200, in attach_volume
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi volume = self.volume_api.get(context, volume_id)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/volume/cinder.py", line 397, in wrapper
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi res = method(self, ctx, *args, **kwargs)
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi File "/usr/lib/python3/dist-packages/nova/volume/cinder.py", line 433, in wrapper
2020-03-01 22:35:10.559 3917 ERROR nova.api.openstack.wsgi res = method(self, ctx, volume_id, *args, **kwargs)
2020-03-01 22:35:10.559 3917 ERRO...

[Sylvain Bauza (sylvain-bauza)]

From what I've seen, nova just tries to use the configured token section for calling the Cinder API thru cinderclient and this doesn't work.

FWIW, you probably have a misconfigured [cinder] section in nova.conf and if you use Fernet tokens, please read https://docs.openstack.org/keystone/pike/admin/identity-fernet-token-faq.html for verifying all the steps (including how to deliver all the keys).

Closing the bug as of now as there is no evidence of something wrong in the nova source code but feel free to reopen the bug if you find some trace that nova misuses how to connect Cinder.

[Dmytro Kostinov (dmikos)]

Hello gadLinux.

Did you solve this problem?
If you solved it, can you tell me how?

I have the same problem and and i'm stumped.
https://bugs.launchpad.net/nova/+bug/1945301

Thank you.