Improve configuration variable troubleshooting with DEBUG logs, more helpful errors, and unit tests

CHANGELOG.md

@@ -19,6 +19,10 @@ The types of changes are:
 
 ## [Unreleased](https://github.com/ethyca/fidesops/compare/1.5.1...main)
 
+### Added
+* Added `FIDESOPS__SECURITY__LOG_LEVEL` configuration variable to allow controlling the log level [#579](https://github.com/ethyca/fidesops/pull/579)
+* Added `DEBUG` logs at startup to view all configuration values [#579](https://github.com/ethyca/fidesops/pull/579)
+
 ### Changed
 * Use the `RuleResponse` schema within the `PrivacyRequestReposnse` schema [#580](https://github.com/ethyca/fidesops/pull/580)
 

data/config/fidesops.toml

@@ -0,0 +1,33 @@
+# Configuration TOML used in select unit tests
+
+[database]
+SERVER="testserver"
+USER="testuser"
+PASSWORD="testpassword"
+DB="testdb"
+TEST_DB="test_testdb"
+ENABLED=true
+
+[redis]
+HOST="testredis"
+PASSWORD="testpassword"
+PORT=1234
+CHARSET="utf8"
+DEFAULT_TTL_SECONDS=1000
+DB_INDEX=0
+ENABLED=true
+
+[security]
+APP_ENCRYPTION_KEY="atestencryptionkeythatisvalidlen"
+CORS_ORIGINS=["http://test.com", "https://test.com"]
+OAUTH_ROOT_CLIENT_ID="testrootclientid"
+OAUTH_ROOT_CLIENT_SECRET="testrootclientsecret"
+DRP_JWT_SECRET="testdrpsecret"
+LOG_LEVEL = "DEBUG"
+
+[execution]
+TASK_RETRY_COUNT=0
+TASK_RETRY_DELAY=1
+TASK_RETRY_BACKOFF=1
+REQUIRE_MANUAL_REQUEST_APPROVAL=false
+MASKING_STRICT=true

docs/fidesops/docs/guides/configuration_reference.md

@@ -45,6 +45,7 @@ The `fidesops.toml` file should specify the following variables:
 |---|---|---|---|---|---|
 | `APP_ENCRYPTION_KEY` | `FIDESOPS__SECURITY__APP_ENCRYPTION_KEY` | string | OLMkv91j8DHiDAULnK5Lxx3kSCov30b3 | N/A | The key used to sign Fidesops API access tokens |
 | `CORS_ORIGINS` | `FIDESOPS__SECURITY__CORS_ORIGINS` | List[AnyHttpUrl] | ["https://a-client.com/", "https://another-client.com"/] | N/A | A list of pre-approved addresses of clients allowed to communicate with the Fidesops application server |
+| `LOG_LEVEL` | `FIDESOPS__SECURITY__LOG_LEVEL` | string | INFO | N/A | The log level used for Fidesops. Must be one of DEBUG, INFO, WARNING, ERROR, or CRITICAL |
 | `OAUTH_ROOT_CLIENT_ID` | `FIDESOPS__SECURITY__OAUTH_ROOT_CLIENT_ID` | string | fidesopsadmin | N/A | The value used to identify the Fidesops application root API client |
 | `OAUTH_ROOT_CLIENT_SECRET` | `FIDESOPS__SECURITY__OAUTH_ROOT_CLIENT_SECRET` | string | fidesopsadminsecret | N/A | The secret value used to authenticate the Fidesops application root API client |
 | `OAUTH_ACCESS_TOKEN_EXPIRE_MINUTES` | `FIDESOPS__SECURITY__OAUTH_ACCESS_TOKEN_EXPIRE_MINUTES` | int | 1 | 11520 | The time period Fidesops API tokens will be valid |

fidesops.toml

@@ -22,6 +22,7 @@ ENCODING="UTF-8"
 OAUTH_ROOT_CLIENT_ID="fidesopsadmin"
 OAUTH_ROOT_CLIENT_SECRET="fidesopsadminsecret"
 DRP_JWT_SECRET="secret"
+LOG_LEVEL = "INFO"
 
 [execution]
 TASK_RETRY_COUNT=0

src/fidesops/core/config.py

@@ -147,9 +147,15 @@ class SecuritySettings(FidesSettings):
     def validate_encryption_key_length(
         cls, v: Optional[str], values: Dict[str, str]
     ) -> Optional[str]:
-        """Validate the encryption key is exactly 32 bytes"""
-        if v is None or len(v.encode(values.get("ENCODING", "UTF-8"))) != 32:
-            raise ValueError("APP_ENCRYPTION_KEY value must be exactly 32 bytes long")
+        """Validate the encryption key is exactly 32 characters"""
+        if v is None:
+            raise ValueError("APP_ENCRYPTION_KEY value not provided!")
+        encryption_key = v.encode(values.get("ENCODING", "UTF-8"))
+        if len(encryption_key) != 32:
+            raise ValueError(
+                f"APP_ENCRYPTION_KEY value must be exactly 32 characters, "
+                f"received {len(encryption_key)} characters!"
+            )
         return v
 
     CORS_ORIGINS: List[AnyHttpUrl] = []
@@ -187,6 +193,29 @@ def assemble_root_access_token(
         hashed_client_id = hashlib.sha512(value.encode(encoding) + salt).hexdigest()
         return hashed_client_id, salt
 
+    LOG_LEVEL: str = "INFO"
+
+    @validator("LOG_LEVEL", pre=True)
+    def validate_log_level(cls, value: str) -> str:
+        """Ensure the provided LOG_LEVEL is a valid value."""
+        valid_values = [
+            logging.DEBUG,
+            logging.INFO,
+            logging.WARNING,
+            logging.ERROR,
+            logging.CRITICAL,
+        ]
+        value = value.upper()  # force uppercase, for safety
+
+        # Attempt to convert the string value (e.g. 'debug') to a numeric level, e.g. 10 (logging.DEBUG)
+        # NOTE: If the string doesn't match a valid level, this will return a string like 'Level {value}'
+        if logging.getLevelName(value) not in valid_values:
+            raise ValueError(
+                f"Invalid LOG_LEVEL provided '{value}', must be one of: DEBUG, INFO, WARNING, ERROR, CRITICAL"
+            )
+
+        return value
+
     class Config:
         env_prefix = "FIDESOPS__SECURITY__"
 
@@ -214,6 +243,17 @@ class Config:  # pylint: disable=C0115
         f'Startup configuration: pii logging = {os.getenv("FIDESOPS__LOG_PII") == "True"}'
     )
 
+    def log_all_config_values(self) -> None:
+        """Output DEBUG logs of all the config values."""
+        for settings in [self.database, self.redis, self.security, self.execution]:
+            for key, value in settings.dict().items():
+                logger.debug(
+                    "Using config: %s%s = %s",
+                    NotPii(settings.Config.env_prefix),
+                    NotPii(key),
+                    NotPii(value),
+                )
+
 
 def load_file(file_name: str) -> str:
     """Load a file and from the first matching location.
@@ -226,7 +266,6 @@ def load_file(file_name: str) -> str:
 
     raises FileNotFound if none is found
     """
-
     possible_directories = [
         os.getenv("FIDESOPS__CONFIG_PATH"),
         os.curdir,
@@ -266,15 +305,15 @@ def get_config() -> FidesopsConfig:
     """
     try:
         return FidesopsConfig.parse_obj(load_toml("fidesops.toml"))
-    except (FileNotFoundError, ValidationError) as e:
+    except (FileNotFoundError) as e:
         logger.warning("fidesops.toml could not be loaded: %s", NotPii(e))
         # If no path is specified Pydantic will attempt to read settings from
         # the environment. Default values will still be used if the matching
         # environment variable is not set.
         try:
             return FidesopsConfig()
         except ValidationError as exc:
-            logger.error("ValidationError: %s", exc)
+            logger.error("Fidesops config could not be loaded: %s", NotPii(exc))
             # If FidesopsConfig is missing any required values Pydantic will throw
             # an ImportError. This means the config has not been correctly specified
             # so we can throw the missing config error.

src/fidesops/main.py

@@ -14,7 +14,7 @@
 from fidesops.tasks.scheduled.tasks import initiate_scheduled_request_intake
 from fidesops.util.logger import get_fides_log_record_factory
 
-logging.basicConfig(level=logging.INFO)
+logging.basicConfig(level=config.security.LOG_LEVEL)
 logging.setLogRecordFactory(get_fides_log_record_factory())
 logger = logging.getLogger(__name__)
 
@@ -38,6 +38,14 @@
 def start_webserver() -> None:
     """Run any pending DB migrations and start the webserver."""
     logger.info("****************fidesops****************")
+
+    if logger.getEffectiveLevel() == logging.DEBUG:
+        logger.warning(
+            "WARNING: log level is DEBUG, so sensitive or personal data may be logged. "
+            "Set FIDESOPS__SECURITY__LOG_LEVEL to INFO or higher in production."
+        )
+        config.log_all_config_values()
+
     if config.database.ENABLED:
         logger.info("Running any pending DB migrations...")
         init_db(config.database.SQLALCHEMY_DATABASE_URI, config.package.PATH)

tests/core/test_config.py

@@ -0,0 +1,109 @@
+import logging
+import os
+from unittest.mock import patch
+
+import pytest
+from pydantic import ValidationError
+
+from fidesops.core.config import get_config
+
+
+def test_config_from_default() -> None:
+    "Test building a config from default local TOML"
+    config = get_config()
+
+    assert config.database.SERVER == "db"
+    assert config.redis.HOST == "redis"
+    assert config.security.APP_ENCRYPTION_KEY == "OLMkv91j8DHiDAULnK5Lxx3kSCov30b3"
+
+
+@patch.dict(
+    os.environ,
+    {
+        "FIDESOPS__CONFIG_PATH": "data/config/",
+    },
+    clear=True,
+)
+def test_config_from_path() -> None:
+    """Test reading config using the FIDESOPS__CONFIG_PATH option."""
+    config = get_config()
+    assert config.database.SERVER == "testserver"
+    assert config.redis.HOST == "testredis"
+    assert config.security.APP_ENCRYPTION_KEY == "atestencryptionkeythatisvalidlen"
+
+
+@patch.dict(
+    os.environ,
+    {
+        "FIDESOPS__DATABASE__SERVER": "envserver",
+        "FIDESOPS__REDIS__HOST": "envhost",
+    },
+    clear=True,
+)
+def test_config_from_env_vars() -> None:
+    """Test overriding config using ENV vars."""
+    config = get_config()
+    assert config.database.SERVER == "envserver"
+    assert config.redis.HOST == "envhost"
+    assert config.security.APP_ENCRYPTION_KEY == "OLMkv91j8DHiDAULnK5Lxx3kSCov30b3"
+
+
+@pytest.mark.parametrize(
+    "app_encryption_key,expected_error",
+    [
+        ("tooshortkey", "must be exactly 32 characters, received 11"),
+        (
+            "muchmuchmuchmuchmuchmuchmuchmuchtoolongkey",
+            "must be exactly 32 characters, received 42",
+        ),
+        ("atestencryptionkeythatisvalidlen", None),
+    ],
+)
+def test_config_app_encryption_key_validation(
+    app_encryption_key, expected_error
+) -> None:
+    """Test APP_ENCRYPTION_KEY is validated to be exactly 32 characters."""
+    with patch.dict(
+        os.environ,
+        {
+            "FIDESOPS__SECURITY__APP_ENCRYPTION_KEY": app_encryption_key,
+        },
+        clear=True,
+    ):
+        if expected_error is not None:
+            with pytest.raises(ValidationError) as err:
+                config = get_config()
+            assert expected_error in str(err.value)
+        else:
+            config = get_config()
+            assert config.security.APP_ENCRYPTION_KEY == app_encryption_key
+
+
+@pytest.mark.parametrize(
+    "log_level,expected_log_level",
+    [
+        ("DEBUG", "DEBUG"),
+        ("debug", "DEBUG"),
+        ("INFO", "INFO"),
+        ("WARNING", "WARNING"),
+        ("ERROR", "ERROR"),
+        ("CRITICAL", "CRITICAL"),
+        ("INVALID", None),
+    ],
+)
+def test_config_log_level(log_level, expected_log_level):
+    """Test overriding the log level using ENV vars."""
+    with patch.dict(
+        os.environ,
+        {
+            "FIDESOPS__SECURITY__LOG_LEVEL": log_level,
+        },
+        clear=True,
+    ):
+        if expected_log_level is not None:
+            config = get_config()
+            assert config.security.LOG_LEVEL == expected_log_level
+        else:
+            with pytest.raises(ValidationError) as err:
+                config = get_config()
+            assert "Invalid LOG_LEVEL" in str(err.value)