Nova/Cinder Key Manager for Barbican Uses Stale Cache

[Dave McCowan]

The Key Manger for Barbican, implemented in Nova and Cinder, caches a value of barbican_client to save extra
calls to Keystone for authentication. However, the cached value of barbican_client is only valid for the current
context. A check needs to be made to ensure the context has not changed before using the saved value.

The symptoms for using a stale cache value include getting the following error message when creating
an encrypted volume.

From CLI:
---------------
openstack volume create --size 1 --type LUKS encrypted_volume
The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-aea6be92-020e-41ed-ba88-44a1f5235ab0)

In cinder.log
-------------------
2015-12-03 09:09:03.648 TRACE cinder.volume.api Traceback (most recent call last):
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 82, in _exe
cute_task
2015-12-03 09:09:03.648 TRACE cinder.volume.api result = task.execute(**arguments)
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/volume/flows/api/create_volume.py", line 409, in execute
2015-12-03 09:09:03.648 TRACE cinder.volume.api source_volume)
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/volume/flows/api/create_volume.py", line 338, in _get_encryption_key_
id
2015-12-03 09:09:03.648 TRACE cinder.volume.api encryption_key_id = key_manager.create_key(context)
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/keymgr/barbican.py", line 147, in create_key
2015-12-03 09:09:03.648 TRACE cinder.volume.api LOG.exception(_LE("Error creating key."))
….
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 502, in post
2015-12-03 09:09:03.648 TRACE cinder.volume.api return self.request(url, 'POST', **kwargs)
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/usr/lib/python2.7/site-packages/keystoneclient/utils.py", line 337, in inner
2015-12-03 09:09:03.648 TRACE cinder.volume.api return func(*args, **kwargs)
2015-12-03 09:09:03.648 TRACE cinder.volume.api File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 402, in request
2015-12-03 09:09:03.648 TRACE cinder.volume.api raise exceptions.from_response(resp, method, url)
2015-12-03 09:09:03.648 TRACE cinder.volume.api Unauthorized: The request you have made requires authentication. (Disable debug mode to suppress these details.) (HTTP 401) (Request-ID: req-d2c52e0b-c16d-43ec-a7a0-7611113f1270)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/254357

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/254358

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/254357
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=0832a0355381229ece235440a9c5de1301e51d07
Submitter: Jenkins
Branch: master

commit 0832a0355381229ece235440a9c5de1301e51d07
Author: Dave McCowan <email address hidden>
Date: Mon Dec 7 14:25:24 2015 -0500

    Check context before returning cached value

    The key manager caches the value of barbican client to be reused,
    saving an extra call to keystone. The cached value is only
    applicable to the current context, so the context must be checked
    before returning the cached value.

    Change-Id: Ib10909a098fb2cd070129c239b6d3b95edc8fea0
    Closes-Bug: #1523646

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/257638

[Nguyen Truong Son (hunters1094)]

Apply patch for cinder but not success.

[Dave McCowan (dave-mccowan)]

@hunters1094-- Would you please provide the steps you took to generate the attached log?

[Nguyen Truong Son (hunters1094)]

Hi Dave

I deploy my own Openstack manual, with project Nova, Cinder, Barbican ....

Barbican I deploy by using babican.sh install.

When I create volume with encryption, it sometimes reports ERROR with my log.

Thanks

[Nguyen Truong Son (hunters1094)]

Sometimes, It also occurs when I delete a encrypted volume.

Do you need more info?

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/255323
Committed: https://git.openstack.org/cgit/openstack/castellan/commit/?id=43efbf1d5fc9b3ebfef38f2e4fa016c247fb15b1
Submitter: Jenkins
Branch: master

commit 43efbf1d5fc9b3ebfef38f2e4fa016c247fb15b1
Author: Dave McCowan <email address hidden>
Date: Wed Dec 9 10:37:24 2015 -0500

    Move line of code to ensure context and client stay in sync

    If the barbican_client.Client() throws an exception, then
    self._current_context will not match self._barbican_client.
    This fix moves a line of code down to ensure they will match.

    Change-Id: I4e6291d98d9b2d37b3d5063b9b20fbb093d254d4
    Closes-bug: #1523646

[Nguyen Truong Son (hunters1094)]

@ Dave: In cinder I still get this bug. Sometimes when I create or delete encrypted volume. And if I restart cinder-api, I can do it ok.

Thanks.

[Dave McCowan (dave-mccowan)]

Hi Nguyen--
    Do you see this symptom after cinder-api has been running for a while? Specifically: create a volume, wait one hour, then create a second volume?
    I just double-checked on a fresh install of /master that this case is fixed for me. Are you sure you have the fixed code installed?
--Dave

[Nguyen Truong Son (hunters1094)]

Hi Dave
It seams to be OK now. Maybe there is error in my source control software.

I have checked the case: create a volume, wait one hour, then create a second volume

Thanks.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/266678

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/kilo
Review: https://review.openstack.org/266680

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/254358
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=676a53ce44a5624a553e80bcff339300802d5494
Submitter: Jenkins
Branch: master

commit 676a53ce44a5624a553e80bcff339300802d5494
Author: Dave McCowan <email address hidden>
Date: Mon Dec 7 14:28:52 2015 -0500

    Check context before returning cached value

    The key manager caches the value of barbican client to be reused,
    saving an extra call to keystone. The cached value is only
    applicable to the current context, so the context must be checked
    before returning the cached value.

    Closes-Bug: #1523646

    Change-Id: I7cd7f1ba8a749b230c611e4fb20ccf4127354c35

[Thierry Carrez (ttx)]

This issue was fixed in the openstack/nova 13.0.0.0b2 development milestone.

[Thierry Carrez (ttx)]

This issue was fixed in the openstack/cinder 8.0.0.0b2 development milestone.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/266678
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=aa2fdfc47a835dfffdacd25e33818a761a407c8e
Submitter: Jenkins
Branch: stable/liberty

commit aa2fdfc47a835dfffdacd25e33818a761a407c8e
Author: Dave McCowan <email address hidden>
Date: Mon Dec 7 14:25:24 2015 -0500

    Check context before returning cached value

    The key manager caches the value of barbican client to be reused,
    saving an extra call to keystone. The cached value is only
    applicable to the current context, so the context must be checked
    before returning the cached value.

    Change-Id: Ib10909a098fb2cd070129c239b6d3b95edc8fea0
    Closes-Bug: #1523646
    (cherry picked from commit 0832a0355381229ece235440a9c5de1301e51d07)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/288490

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/288490
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=8db72b99f2d580cb2930041c15c04b73731fda76
Submitter: Jenkins
Branch: stable/liberty

commit 8db72b99f2d580cb2930041c15c04b73731fda76
Author: Dave McCowan <email address hidden>
Date: Mon Dec 7 14:28:52 2015 -0500

    Check context before returning cached value

    The key manager caches the value of barbican client to be reused,
    saving an extra call to keystone. The cached value is only
    applicable to the current context, so the context must be checked
    before returning the cached value.

    Closes-Bug: #1523646

    Change-Id: I7cd7f1ba8a749b230c611e4fb20ccf4127354c35
    (cherry picked from commit 676a53ce44a5624a553e80bcff339300802d5494)

[Robert Clark (robert-clark)]

Dave, whats required to finish up the OSSN for this? I can't see a draft in the queue?

[Davanum Srinivas (DIMS) (dims-v)]

This issue was fixed in the openstack/nova 12.0.3 release.

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/cinder 7.0.2 release.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Dave Walker (<email address hidden>) on branch: stable/kilo
Review: https://review.openstack.org/266680
Reason: Kilo is now approaching EOL. We are in freeze pending the final release and no freeze exception has been raised. Therefore I am abandoning this change, if it is required in the release - please restore and raise a request. Thanks

[Dave McCowan (dave-mccowan)]

Review for OSSN: https://review.openstack.org/#/c/267800/

[Nathan Kinder (nkinder)]

This issue has been published as OSSN-0063 on the mailing lists and wiki:

  https://wiki.openstack.org/wiki/OSSN/OSSN-0063

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/cinder 7.0.2 release.