EC2 API Auth Failure

[Nikita Kalyanov]

When trying to validate user token through Keystone an inconsistent behavior is observed:
The very first request for a given user to Keystone is successful, while the second and subsequent requests for the same user result in a Key Error in Keystone _decrypt_credential method and thus auth failure (See the attached traceback). The problem is observed by merely repeating the same aws-cli commands for the same user 2 or more times.

After inserting some debug log messages in core.py the problem seem to happen in _get_credential method in keystone.credential.core:

In first request to Keystone:
Aug 15 20:14:13 ubuntu-vm6 <email address hidden>[22678]: #033[00;36mINFO keystone.credential.core [#033[01;36mNone req-14485eaa-4172-4074-ac28-aa22fea7ce32 #033[00;36mNone None#033[00;36m] #033[01;35m#033[00;36mcontents of credential after _get_credential are user_id=u'4ad247ca077743078bf6109ff5c57dc1', key_hash=u'716d67b1efbe8c7b46d13e6f4b5ccfbe095a3f73', encrypted_blob=u'gAAAAABdVZLCpdDXGjdHk3kglftCMUDnxOKWNuLR6_6ZJtVTFt7VvJ-Y7VzyfxO6JwDv88OQtSMlJzbG8hUcfFftqhH6l5jpx6eNXdhTpO6_ZF57xyey1BmFI8JYh-PWdJkYtfDsOWJzCyWACQaUXU9N2J_r83xEYx691ToCwGCrkL-NgfFX-hVy3dYl9_4-5HcCOR4RoK2VXjLdvuAjWdvWCAxiVs-kxARpT0jkoZP1dnw-zs3pgDE=', project_id=u'9be611818d0b4bac82ea0d468f91541b', type=u'ec2', id=u'11755be627c5e6f22f3a31062afbd631bbe0f3176701ea23e5284920ded89e76'#033[00m#033[00m

In second request to Keystone:
Aug 15 20:14:43 ubuntu-vm6 <email address hidden>[22678]: #033[00;36mINFO keystone.credential.core [#033[01;36mNone req-4e4cc471-f9c7-461b-9245-65f8ac8c843b #033[00;36mNone None#033[00;36m] #033[01;35m#033[00;36mcontents of credential after _get_credential are user_id=u'4ad247ca077743078bf6109ff5c57dc1', blob=u'{"access": "09b2bb6d93ff47098198ceaf060baa8a", "secret": "d25c0c2c4ef542a29f84e7924ec89773", "trust_id": null}', project_id=u'9be611818d0b4bac82ea0d468f91541b', type=u'ec2', id=u'11755be627c5e6f22f3a31062afbd631bbe0f3176701ea23e5284920ded89e76'#033[00m#033[00m

=> Basically _get_credential method returns normal encrypted credential (encrypted_blob) for the first call, and an unencrypted credential (blob) for the second and subsequent calls by the same credential_id after 30 seconds. After that, the already decrypted credential incorrectly returned by _get_credential is passed to _decrypt_credential which fails because there is no 'encrypted_blob' key in the dictionary. The stack trace for the second and subsequent calls led to a package named 'dogpile' and some cache-related methods inside it.

The problem seem to happen due to in-place modification of the credential dictionary in _decrypt_credential method. During the first request to Keystone the normal encrypted credential dictionary is returned by _get_credential method and the returned result is cached. However, after that the credential dictionary is modified in-place by _decrypt_credential method. For the second and subsequent calls to the _get_credential for the same user it tries to return the result from cache. But the cached result has been modified by _decrypt_credential. So, the already decrypted during first request credential is returned and passed again to _decrypt_credential breaking it.

The solution is to modify a copy of the credential dictionary inside _decrypt_credential method, not the original credential in-place (the same approach as in _encrypt_credential where a copy is modified). This way the encrypted value of the credential is cached and it does not gets modified afterwards. So the normal encrypted credential is returned from cache and passed to _decrypt_credential again and again even for the same user which fixes the problem.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/677239

[Guang Yee (guang-yee)]

I am unable to reproduce the problem in devstack. Can you please let me know how to reproduce the problem?

vagrant@devstack:~$ source devstack/openrc
WARNING: setting legacy OS_TENANT_NAME to support cli tools.
vagrant@devstack:~$ openstack ec2 credentials create
+------------+------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+------------+------------------------------------------------------------------------------------------------------------------------------------------+
| access | d58750aab57546b8838bfb072ca9f39b |
| links | {u'self': u'http://192.168.1.20/identity/v3/users/aaf1da0b2dee4a89be8350533d40628b/credentials/OS-EC2/d58750aab57546b8838bfb072ca9f39b'} |
| project_id | 5f5b5ca4fffe4a90b15149c4e9b12222 |
| secret | 1a6895b1d1f549a693795d93f41aef90 |
| trust_id | None |
| user_id | aaf1da0b2dee4a89be8350533d40628b |
+------------+------------------------------------------------------------------------------------------------------------------------------------------+
vagrant@devstack:~$ openstack ec2 credentials create
+------------+------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+------------+------------------------------------------------------------------------------------------------------------------------------------------+
| access | 7f003b5f4b7945c8aa6db512021111ab |
| links | {u'self': u'http://192.168.1.20/identity/v3/users/aaf1da0b2dee4a89be8350533d40628b/credentials/OS-EC2/7f003b5f4b7945c8aa6db512021111ab'} |
| project_id | 5f5b5ca4fffe4a90b15149c4e9b12222 |
| secret | ad22cbc8d02744f4b38d65ab1f17ef0e |
| trust_id | None |
| user_id | aaf1da0b2dee4a89be8350533d40628b ...

[Nikita Kalyanov (nikitakalyanov)]

I was testing with describe-images and other commands seen in functional
tests in particular, not sure how 'credentials list' works. Please see this
https://review.opendev.org/#/c/676894
You could execute the 'create_config' script from this change and you
sholud see the same failure as in Zuul logs for this job. It uses aws-cli
but the partucular client does not matter - the functional tests use boto
library and also fail.

сб, 14 сент. 2019, 1:41 Guang Yee <email address hidden>:

> I am unable to reproduce the problem in devstack. Can you please let me
> know how to reproduce the problem?
>
> vagrant@devstack:~$ source devstack/openrc
> WARNING: setting legacy OS_TENANT_NAME to support cli tools.
> vagrant@devstack:~$ openstack ec2 credentials create
>
> +------------+------------------------------------------------------------------------------------------------------------------------------------------+
> | Field | Value
>
> |
>
> +------------+------------------------------------------------------------------------------------------------------------------------------------------+
> | access | d58750aab57546b8838bfb072ca9f39b
>
> |
> | links | {u'self': u'
> http://192.168.1.20/identity/v3/users/aaf1da0b2dee4a89be8350533d40628b/credentials/OS-EC2/d58750aab57546b8838bfb072ca9f39b'}
> |
> | project_id | 5f5b5ca4fffe4a90b15149c4e9b12222
>
> |
> | secret | 1a6895b1d1f549a693795d93f41aef90
>
> |
> | trust_id | None
>
> |
> | user_id | aaf1da0b2dee4a89be8350533d40628b
>
> |
>
> +------------+------------------------------------------------------------------------------------------------------------------------------------------+
> vagrant@devstack:~$ openstack ec2 credentials create
>
> +------------+------------------------------------------------------------------------------------------------------------------------------------------+
> | Field | Value
>
> |
>
> +------------+------------------------------------------------------------------------------------------------------------------------------------------+
> | access | 7f003b5f4b7945c8aa6db512021111ab
>
> |
> | links | {u'self': u'
> http://192.168.1.20/identity/v3/users/aaf1da0b2dee4a89be8350533d40628b/credentials/OS-EC2/7f003b5f4b7945c8aa6db512021111ab'}
> |
> | project_id | 5f5b5ca4fffe4a90b15149c4e9b12222
>
> |
> | secret | ad22cbc8d02744f4b38d65ab1f17ef0e
>
> |
> | trust_id | None
>
> |
> | user_id | aaf1da0b2dee4a89be8350533d40628b
>
> |
>
> +------------+------------------------------------------------------------------------------------------------------------------------------------------+
> vagrant@devstack:~$ openstack ec2 credentials list
>
> +----------------------------------+----------------------------------+----------------------------------+----------------------------------+
> | Access | Secret |
> Project ID | User ID |
>
> +----------------------------------+----------------------------------+----------------------------------+----------------------------------+
> | d58750aab57546b8838bfb072ca9f39b |...

[Morgan Fainberg (mdrnstm)]

As shown here:

https://storage.gra1.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_d9c/680481/1/check/ec2-api-functional-neutron/d9c3627/logs/etc/keystone/keystone.conf.txt.gz

You are using 'backend = oslo_cache.dict' this is no way is representative of any configuration that should be run in production. The dict backend will have odd edge cases and potential problems such as mutability of the cached data. The data is housed in-memory within the process.

Use memcached.

This is not a bug. Marking as invalid.

[Morgan Fainberg (mdrnstm)]

Sorry, marking as wont fix.

[Morgan Fainberg (mdrnstm)]

This might be worth fixing in oslo_cache, forcing the dict backend to serialize/deserialize may solve your issue. Likewise, the oslo_cache dict backend could explicitly copy on a .get. Keystone is behaving as expected and should error if you try and decrypt the same data more than once -- the decrypted data should never be cached.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Lance Bragstad (<email address hidden>) on branch: master
Review: https://review.opendev.org/677239
Reason: Abandoning as requested.