yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1864387] [NEW] Attaching volume fails with cinderclient.exceptions.Unauthorized

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: gadLinux <1864387@xxxxxxxxxxxxxxxxxx>
Date: Sun, 23 Feb 2020 20:25:09 -0000
Reply-to: Bug 1864387 <1864387@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

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,

** 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/1864387

Title:
  Attaching volume fails with cinderclient.exceptions.Unauthorized

Status in OpenStack Compute (nova):
  New

Bug description:
  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,

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1864387/+subscriptions
Follow ups

[Bug 1864387] Re: Attaching volume fails with cinderclient.exceptions.Unauthorized
From: Sylvain Bauza, 2020-04-15