Empty Fernet Key Files causing problems with token issue

Bug #1728907 reported by Divya K Konoor
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Identity (keystone)
Fix Released
Low
Gage Hugo

Bug Description

The problem being reported is very similar to the one reported at https://bugs.launchpad.net/keystone/+bug/1642457 but not the same.

Step to reproduce (Not sure of the chances of being able to reproduce this again but these were the steps that happened when the problem was found):

1. Fernet token rotation is configured in this environment to run via a cron job every 3 hours. The primary key when things were working was 58. The system (where OpenStack was installed) went out of memory and in an attempt to recover, a reboot was initiated. As fate would have it, the reboot was initiated at 14.58 and the key rotate was to happen at 15:02. Keystone logs don't have any logging between 14.58 and 15:15. When the system was up, token issue was failing with

File "/usr/lib64/python2.7/site-packages/cryptography/fernet.py", line 37, in __init__
2017-10-26 15:46:30.613 4767 ERROR keystone.common.wsgi "Fernet key must be 32 url-safe base64-encoded bytes."
2017-10-26 15:46:30.613 4767 ERROR keystone.common.wsgi ValueError: Fernet key must be 32 url-safe base64-encoded bytes.

2. Soon after the above was noticed , a key rotation was attempted to see if that fixes anything (/usr/bin/keystone-manage fernet_rotate --keystone-user keystone --keystone-group keystone). And it did not.

3. When the fernet-keys directory was checked after step 3, an empty primary key file was found(60) . No other files were empty. This file was manually deleted after which the primary key became 59 and token issue continued to work.

System has no problem with disk space.

tags: added: fernet
Changed in keystone:
importance: Undecided → Low
status: New → Triaged
Revision history for this message
Lance Bragstad (lbragstad) wrote :

This seems somewhat familiar to bug 1642457.

tags: added: office-hours
Revision history for this message
Gage Hugo (gagehugo) wrote :

Was able to replicate this I believe:

- With primary fernet key as "1", create an empty key file "2".
- Perform keystone-manage fernet_rotate (which passes)[0]
- Try to authenticate [1]
- Verified "2" is an empty file

[0]

2018-02-21 12:01:57.926 3643 INFO keystone.common.token_utils [-] Starting key rotation with 3 key files: ['/etc/keystone/fernet-keys/0', '/etc/keystone/fernet-keys/1', '/etc/keystone/fernet-keys/2']
2018-02-21 12:01:57.928 3643 INFO keystone.common.token_utils [-] Created a new temporary key: /etc/keystone/fernet-keys/0.tmp
2018-02-21 12:01:57.929 3643 INFO keystone.common.token_utils [-] Current primary key is: 2
2018-02-21 12:01:57.931 3643 INFO keystone.common.token_utils [-] Next primary key will be: 3
2018-02-21 12:01:57.932 3643 INFO keystone.common.token_utils [-] Promoted key 0 to be the primary: 3
2018-02-21 12:01:57.933 3643 INFO keystone.common.token_utils [-] Become a valid new key: /etc/keystone/fernet-keys/0
2018-02-21 12:01:57.934 3643 INFO keystone.common.token_utils [-] Excess key to purge: /etc/keystone/fernet-keys/1

[1]

2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi File "/usr/local/lib/python2.7/dist-packages/keystone/token/token_formatters.py", line 79, in pack
2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi return self.crypto.encrypt(payload).rstrip(b'=').decode('utf-8')
2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi File "/usr/local/lib/python2.7/dist-packages/keystone/token/token_formatters.py", line 68, in crypto
2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi fernet_instances = [fernet.Fernet(key) for key in keys]
2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi File "/usr/local/lib/python2.7/dist-packages/cryptography/fernet.py", line 37, in __init__
2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi "Fernet key must be 32 url-safe base64-encoded bytes."
2018-02-21 12:05:30.198 14496 ERROR keystone.common.wsgi ValueError: Fernet key must be 32 url-safe base64-encoded bytes.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (master)

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

Changed in keystone:
assignee: nobody → Gage Hugo (gagehugo)
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (master)

Reviewed: https://review.openstack.org/546785
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=f2a210e3fe991885833a627a9e45b6f0e4669b34
Submitter: Zuul
Branch: master

commit f2a210e3fe991885833a627a9e45b6f0e4669b34
Author: Gage Hugo <email address hidden>
Date: Wed Feb 21 15:45:17 2018 -0600

    Handle empty token key files

    In some rare cases, an empty key file can get created within the fernet
    key repository. When keystone tries to load the keys from disk, it will
    fail with an invalid fernet key ValueError.

    This change adds a check for empty files with a valid numerical name
    within the key repository when rotating keys and loading keys. If an
    empty file exists, it will be ignored when loading keys, reported in the
    logs, and overwritten with a valid key upon rotation.

    Change-Id: Ic19dd02d38e8f6a05c8951ec3dd13659aab98259
    Closes-Bug: 1728907

Changed in keystone:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/keystone 14.0.0.0b2

This issue was fixed in the openstack/keystone 14.0.0.0b2 development milestone.

Changed in keystone:
milestone: none → rocky-2
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.