Merge "Emit log message for fernet tokens only"

keystone/common/fernet_utils.py

@@ -256,15 +256,18 @@ class FernetUtils(object):
 
         if len(keys) != self.max_active_keys:
             # Once the number of keys matches max_active_keys, this log entry
-            # is too repetitive to be useful.
+            # is too repetitive to be useful. Also note that it only makes
-            LOG.debug(
+            # sense to log this message for tokens since credentials doesn't
-                'Loaded %(count)d Fernet keys from %(dir)s, but '
+            # have a `max_active_key` configuration option.
-                '`[fernet_tokens] max_active_keys = %(max)d`; perhaps there '
+            if self.key_repository == CONF.fernet_tokens.key_repository:
-                'have not been enough key rotations to reach '
+                LOG.debug(
-                '`max_active_keys` yet?', {
+                    'Loaded %(count)d Fernet keys from %(dir)s, but '
-                    'count': len(keys),
+                    '`[fernet_tokens] max_active_keys = %(max)d`; perhaps '
-                    'max': self.max_active_keys,
+                    'there have not been enough key rotations to reach '
-                    'dir': self.key_repository})
+                    '`max_active_keys` yet?', {
+                        'count': len(keys),
+                        'max': self.max_active_keys,
+                        'dir': self.key_repository})
 
         # return the encryption_keys, sorted by key number, descending
         return [keys[x] for x in sorted(keys.keys(), reverse=True)]

keystone/tests/unit/common/test_utils.py

@@ -12,16 +12,21 @@
 # under the License.
 
 import datetime
+import fixtures
 import uuid
 
 from oslo_config import fixture as config_fixture
+from oslo_log import log
 from oslo_serialization import jsonutils
 import six
 
+from keystone.common import fernet_utils
 from keystone.common import utils as common_utils
 import keystone.conf
+from keystone.credential.providers import fernet as credential_fernet
 from keystone import exception
 from keystone.tests import unit
+from keystone.tests.unit import ksfixtures
 from keystone.tests.unit import utils
 from keystone.version import service
 
@@ -204,3 +209,54 @@ class ServiceHelperTests(unit.BaseTestCase):
 
     def test_fail_gracefully(self):
         self.assertRaises(unit.UnexpectedExit, self._do_test)
+
+
+class FernetUtilsTestCase(unit.BaseTestCase):
+
+    def setUp(self):
+        super(FernetUtilsTestCase, self).setUp()
+        self.config_fixture = self.useFixture(config_fixture.Config(CONF))
+
+    def test_debug_message_logged_when_loading_fernet_token_keys(self):
+        self.useFixture(
+            ksfixtures.KeyRepository(
+                self.config_fixture,
+                'fernet_tokens',
+                CONF.fernet_tokens.max_active_keys
+            )
+        )
+        logging_fixture = self.useFixture(fixtures.FakeLogger(level=log.DEBUG))
+        fernet_utilities = fernet_utils.FernetUtils(
+            CONF.fernet_tokens.key_repository,
+            CONF.fernet_tokens.max_active_keys
+        )
+        fernet_utilities.load_keys()
+        expected_debug_message = (
+            'Loaded 2 Fernet keys from %(dir)s, but `[fernet_tokens] '
+            'max_active_keys = %(max)d`; perhaps there have not been enough '
+            'key rotations to reach `max_active_keys` yet?') % {
+                'dir': CONF.fernet_tokens.key_repository,
+                'max': CONF.fernet_tokens.max_active_keys}
+        self.assertIn(expected_debug_message, logging_fixture.output)
+
+    def test_debug_message_not_logged_when_loading_fernet_credential_key(self):
+        self.useFixture(
+            ksfixtures.KeyRepository(
+                self.config_fixture,
+                'credential',
+                CONF.fernet_tokens.max_active_keys
+            )
+        )
+        logging_fixture = self.useFixture(fixtures.FakeLogger(level=log.DEBUG))
+        fernet_utilities = fernet_utils.FernetUtils(
+            CONF.credential.key_repository,
+            credential_fernet.MAX_ACTIVE_KEYS
+        )
+        fernet_utilities.load_keys()
+        debug_message = (
+            'Loaded 2 Fernet keys from %(dir)s, but `[fernet_tokens] '
+            'max_active_keys = %(max)d`; perhaps there have not been enough '
+            'key rotations to reach `max_active_keys` yet?') % {
+                'dir': CONF.credential.key_repository,
+                'max': credential_fernet.MAX_ACTIVE_KEYS}
+        self.assertNotIn(debug_message, logging_fixture.output)