Stop logging the API key, and apply the log level and label settings

README.md

@@ -40,6 +40,38 @@ calls into the SDK against its type annotations. No pydantic mypy plugin is need
 - The blocking client, `permit.sync.Permit`, is typed as blocking:
   `permit.api.users.get("user")` returns a `UserRead`, not a coroutine.
 
+## Logging
+
+The SDK logs with [loguru](https://github.com/Delgan/loguru) and logs nothing unless you
+enable it in the `log` option:
+
+```py
+permit = Permit(token="<YOUR_API_KEY>", log={"enable": True, "level": "debug"})
+```
+
+- The SDK adds no loguru sink of its own. Its records go to the sinks your application has
+  added, or to loguru's default stderr sink, in the format of those sinks.
+- `"enable": False` (the default) calls loguru's `logger.disable("permit")`. `"enable": True`
+  undoes that call, with `logger.enable("permit")`, only if an earlier client made it, so a
+  `logger.disable()` your application made for `permit` or one of its modules still
+  applies. When it does undo it, loguru also drops any `permit.*` module disable made since.
+- `level` (default `"info"`) is the lowest severity the SDK logs. Its records below it never
+  reach a sink. Your application's own records are not affected. The SDK logs its HTTP
+  requests and the PDP's responses at `"debug"`. With `"enable": True`, for a level name
+  loguru does not know, the SDK logs a warning that names it and uses `"info"`.
+- `label` (default `"Permit"`) is put in square brackets before every message the SDK logs.
+- `json` is not applied. For JSON output, give your application a serialized sink in place
+  of loguru's default one: `logger.remove()`, then `logger.add(sys.stderr, serialize=True)`.
+  Added next to the default sink, it prints every record a second time.
+- loguru's logger is process-wide, so these settings are too: the client created last
+  decides whether the SDK logs, and the last one created with `"enable": True` decides the
+  level and the label, for every client in the process. `wait_for_sync()` creates no
+  client: it yields a copy of the client it is called on.
+- The SDK replaces the API key of every client in the process with `[REDACTED]` in the
+  messages it logs and in the PDP error bodies it puts in a `PermitConnectionError`, so a
+  PDP that echoes the key back does not expose it. A user name and password written into
+  the `api_url` or `pdp` URL are not replaced: the SDK logs its request URLs at `"debug"`.
+
 ## Deprecations
 
 A future major release, permit 4.0, will remove the following. They still work in 3.x, and

permit/api/base.py

@@ -2,10 +2,10 @@
 
 import aiohttp
 from aiohttp import ClientTimeout
-from loguru import logger
 
 from permit.api.encoders import jsonable_encoder
 from permit.utils.pydantic_version import PYDANTIC_VERSION
+from permit.utils.sdk_logger import sdk_logger
 
 if TYPE_CHECKING:
     # The v1 API is what runs under either pydantic major, so type-check against it.
@@ -68,10 +68,10 @@ def __init__(
             self._client_config["timeout"] = ClientTimeout(total=timeout)
 
     def _log_request(self, url: str, method: str) -> None:
-        logger.debug(f"Sending HTTP request: {method} {url}")
+        sdk_logger.debug(f"Sending HTTP request: {method} {url}")
 
     def _log_response(self, url: str, method: str, status: int) -> None:
-        logger.debug(f"Received HTTP response: {method} {url}, status: {status}")
+        sdk_logger.debug(f"Received HTTP response: {method} {url}, status: {status}")
 
     def _prepare_json(
         self, json: BaseModel | dict[str, Any] | list[Any] | None = None
@@ -241,7 +241,7 @@ def _build_http_client(
 
     async def _set_context_from_api_key(self) -> None:
         """Set the API context and permitted access level based on the API key scope."""
-        logger.debug("Fetching api key scope")
+        sdk_logger.debug("Fetching api key scope")
         scope = await self.__api_keys.get("/scope", model=APIKeyScopeRead)
 
         if scope.organization_id is not None:

permit/api/context.py

@@ -1,8 +1,7 @@
 from enum import Enum
 
-from loguru import logger
-
 from permit.exceptions import PermitContextChangeError
+from permit.utils.sdk_logger import sdk_logger
 
 
 class ApiKeyAccessLevel(str, Enum):
@@ -198,7 +197,7 @@ def set_organization_level_context(self, org: str) -> None:
             org: The organization key.
         """
         self.__verify_can_access_org(org)
-        logger.debug(f"Setting organization level context: {org}")
+        sdk_logger.debug(f"Setting organization level context: {org}")
         self._context_level = ApiContextLevel.ORGANIZATION
         self._organization = org
         self._project = None
@@ -212,7 +211,7 @@ def set_project_level_context(self, org: str, project: str) -> None:
             project: The project key.
         """
         self.__verify_can_access_project(org, project)
-        logger.debug(f"Setting project level context: {org}/{project}")
+        sdk_logger.debug(f"Setting project level context: {org}/{project}")
         self._context_level = ApiContextLevel.PROJECT
         self._organization = org
         self._project = project
@@ -227,7 +226,7 @@ def set_environment_level_context(self, org: str, project: str, environment: str
             environment: The environment key.
         """
         self.__verify_can_access_environment(org, project, environment)
-        logger.debug(f"Setting environment level context: {org}/{project}/{environment}")
+        sdk_logger.debug(f"Setting environment level context: {org}/{project}/{environment}")
         self._context_level = ApiContextLevel.ENVIRONMENT
         self._organization = org
         self._project = project

permit/config.py

@@ -13,22 +13,46 @@
 
 
 class LoggerConfig(BaseModel):
-    """Logging settings of the SDK."""
+    """Logging settings of the SDK.
+
+    The SDK logs with loguru and adds no sink of its own: its records go to the loguru sinks
+    the application has added, or to loguru's default stderr sink, in the format of those
+    sinks. loguru's logger is process-wide, so these settings are too: the client created
+    last decides whether the SDK logs, and the last one created with `enable` True decides
+    the level and the label, for every client in the process.
+
+    Whatever these settings, the SDK replaces the API key of every client in the process
+    with `[REDACTED]` in the messages it logs and in the PDP error bodies it puts in a
+    `PermitConnectionError`. A user name and password written into the `api_url` or `pdp`
+    URL are not replaced.
+    """
 
     enable: bool = Field(
-        default=False, description="Whether or not to enable logging from the Permit library"
+        default=False,
+        description="Whether the SDK logs. False calls loguru's logger.disable('permit'), so "
+        "nothing is logged. True undoes that call with logger.enable('permit') if an earlier "
+        "client made it, and otherwise leaves loguru's switches alone, so a logger.disable() "
+        "the application made for 'permit' or one of its modules still applies.",
     )
     level: str = Field(
-        default="info", description="Sets the log level configured for the Permit SDK Logger."
+        default="info",
+        description="The lowest severity the SDK logs, such as 'debug', 'info', 'warning' or "
+        "'error', in any case; 'warn' and 'fatal' are read as 'warning' and 'critical'. The SDK "
+        "drops its records below it before they reach any sink. "
+        "Read only when enable is True; for a name loguru does not know, the SDK logs a "
+        "warning and uses 'info'.",
     )
     label: str = Field(
         default="Permit",
-        description="Sets the label configured for logs emitted by the Permit SDK Logger.",
+        description="Put in square brackets before the message of every record the SDK logs, "
+        "as in '[Permit] ...'. An empty string adds nothing. Read only when enable is True.",
     )
     log_as_json: bool = Field(
         default=False,
         alias="json",
-        description="Sets whether the SDK log output should be in JSON format.",
+        description="Not applied. The format of the SDK's records is that of the loguru sinks "
+        "they reach. For JSON, the application replaces loguru's default sink with a "
+        "serialized one: logger.remove(), then logger.add(sys.stderr, serialize=True).",
     )
 
 
@@ -54,8 +78,11 @@ class PermitConfig(BaseModel):
 
     # A positional `...`, not `default=...`: type checkers take any `default=`
     # keyword as a default, so `PermitConfig()` without a token would pass them.
+    # repr=False keeps the key out of repr() and str() of the config, and so out of
+    # tracebacks that print frame values, such as loguru's with diagnose=True.
     token: str = Field(
         ...,
+        repr=False,
         description="The token (API Key) used for authorization against the PDP "
         "and the Permit REST API.",
     )

permit/enforcement/enforcer.py

@@ -5,7 +5,6 @@
 
 import aiohttp
 from aiohttp import ClientTimeout
-from loguru import logger
 from typing_extensions import NotRequired, TypedDict
 
 from permit.config import PermitConfig
@@ -14,6 +13,7 @@
 from permit.utils.context import Context, ContextStore
 from permit.utils.dicts import deep_merge
 from permit.utils.pydantic_version import PYDANTIC_VERSION
+from permit.utils.sdk_logger import sdk_logger
 from permit.utils.sync import SyncClass
 
 if TYPE_CHECKING:
@@ -53,7 +53,15 @@ async def read_error_body(response: aiohttp.ClientResponse) -> str:
     surrounding handler and re-reported as "cannot connect to the PDP
     container". A 403 for a wrong API key was indistinguishable from the PDP
     being down, which is a genuinely misleading error to hand a user.
+
+    Every API key the SDK knows is replaced with ``[REDACTED]``: the body goes into
+    the SDK's log record and into the PermitConnectionError raised to the caller,
+    and a PDP may echo back the key it rejected.
     """
+    return sdk_logger.scrub(await _read_body_text(response))
+
+
+async def _read_body_text(response: aiohttp.ClientResponse) -> str:
     try:
         return repr(await response.json())
     except (aiohttp.ClientError, ValueError):
@@ -179,7 +187,7 @@ async def authorized_users(
                             raise PermitConnectionError(msg)
 
                         error_body = await read_error_body(response)
-                        logger.error(
+                        sdk_logger.error(
                             "error in permit.authorized_users({}, {}):\n{}\n{}".format(
                                 action,
                                 self._resource_repr(normalized_resource),
@@ -198,7 +206,7 @@ async def authorized_users(
                         raise PermitConnectionError(msg)
 
                     content: dict[str, Any] = await response.json()
-                    logger.debug(
+                    sdk_logger.debug(
                         f"permit.authorized_users() response:"
                         f"\ninput: {pformat(request_body, indent=2)}"
                         f"\nresponse status: {response.status}"
@@ -207,7 +215,7 @@ async def authorized_users(
                     result: AuthorizedUsersResult = parse_obj_as(AuthorizedUsersResult, content)
                     return result
             except aiohttp.ClientError as err:
-                logger.error(
+                sdk_logger.error(
                     f"error in permit.authorized_users({action}, "
                     f"{self._resource_repr(normalized_resource)}):\n{err}"
                 )
@@ -314,10 +322,10 @@ async def bulk_check(
                             f"status code: {response.status}",
                             error_body,
                         )
-                        logger.error(msg)
+                        sdk_logger.error(msg)
                         raise PermitConnectionError(msg)
                     content: dict[str, Any] = await response.json()
-                    logger.debug(
+                    sdk_logger.debug(
                         f"permit.check() response:\n"
                         f"input: {pformat(request_body, indent=2)}\n"
                         f"response status: {response.status}\n"
@@ -339,7 +347,7 @@ async def bulk_check(
                     ),
                     err,
                 )
-                logger.error(msg)
+                sdk_logger.error(msg)
                 raise PermitConnectionError(msg, error=err) from err
             return decisions
 
@@ -416,7 +424,7 @@ async def check(
                             raise PermitConnectionError(msg)
 
                         error_body = await read_error_body(response)
-                        logger.error(
+                        sdk_logger.error(
                             "error in permit.check({}, {}, {}):\n{}\n{}".format(
                                 normalized_user,
                                 action,
@@ -436,7 +444,7 @@ async def check(
                         raise PermitConnectionError(msg)
 
                     content: dict[str, Any] = await response.json()
-                    logger.debug(
+                    sdk_logger.debug(
                         f"permit.check() response:\n"
                         f"body: {pformat(body, indent=2)}\n"
                         f"response status: {response.status}\n"
@@ -445,7 +453,7 @@ async def check(
                     decision: bool = bool(content.get("allow", False))
                     return decision
             except aiohttp.ClientError as err:
-                logger.error(
+                sdk_logger.error(
                     f"error in permit.check({normalized_user}, {action}, "
                     f"{self._resource_repr(normalized_resource)}):"
                     f"\n{err}"
@@ -514,15 +522,15 @@ async def get_user_permissions(
                         else content
                     )
 
-                    logger.debug(
+                    sdk_logger.debug(
                         f"permit.get_user_permissions() response:\n"
                         f"input: {pformat(input_data, indent=2)}\n"
                         f"response data: {pformat(permissions, indent=2)}"
                     )
                     return permissions
 
             except aiohttp.ClientError as err:
-                logger.error(f"Error in permit.get_user_permissions(): {err}")
+                sdk_logger.error(f"Error in permit.get_user_permissions(): {err}")
                 msg = (
                     f"Permit SDK got error: {err}, \n"
                     f"and cannot connect to the PDP container, please check your configuration "

permit/exceptions.py

@@ -5,10 +5,10 @@
 from typing import TYPE_CHECKING, Any, TypeVar
 
 import aiohttp
-from loguru import logger
 from typing_extensions import ParamSpec, deprecated
 
 from permit.utils.pydantic_version import PYDANTIC_VERSION
+from permit.utils.sdk_logger import sdk_logger
 
 if TYPE_CHECKING:
     # The v1 API is what runs under either pydantic major, so type-check against it.
@@ -288,7 +288,7 @@ async def wrapped(*args: P.args, **kwargs: P.kwargs) -> R:
         try:
             return await func(*args, **kwargs)
         except aiohttp.ClientError as err:
-            logger.error(f"got client error while sending an http request:\n{err}")
+            sdk_logger.error(f"got client error while sending an http request:\n{err}")
             msg = f"{err}"
             raise PermitConnectionError(msg, error=err) from err
 

permit/logger.py

@@ -1,15 +1,66 @@
+import contextlib
+
 from loguru import logger
 
 from permit.config import PermitConfig
+from permit.utils.sdk_logger import PACKAGE, sdk_logger
+
+PERMIT_MODULE = PACKAGE
 
-PERMIT_MODULE = "permit"
+# The names Python's logging module also accepts, and the ones the Node SDK's logger uses.
+_LEVEL_ALIASES = {"WARN": "WARNING", "FATAL": "CRITICAL"}
 
 
 def configure_logger(config: PermitConfig) -> None:
-    """Silence the SDK's loguru output unless the config enables logging.
+    """Apply the `log` settings of `config` to the SDK's log records.
+
+    The settings are process-wide, as loguru's logger is: the client created last decides
+    whether the SDK logs, and the last one created with `log.enable` True decides the level
+    and the label, for every client. The SDK adds no sink and leaves the application's sinks
+    and levels alone, so its records are written wherever loguru writes the application's,
+    in the format of those sinks.
+
+    - `log.enable` False calls `logger.disable("permit")`, so nothing is logged. True
+      undoes that call with `logger.enable("permit")` if an earlier client made it, and
+      otherwise leaves loguru's switches alone, so a `logger.disable` the application made
+      for the package or one of its modules still applies.
+    - `log.level` drops the SDK's records below that severity before they reach any sink.
+    - `log.label` is put in brackets before each message.
+    - `log.log_as_json` is not applied: loguru serializes per sink. For JSON output, the
+      application replaces loguru's default sink with a serialized one: `logger.remove()`,
+      then `logger.add(sys.stderr, serialize=True)`.
+
+    Whatever the settings, the API key in `config.token` is replaced with `[REDACTED]` in
+    every message the SDK logs and in the PDP error bodies it puts in a
+    `PermitConnectionError`.
+
+    An unknown `log.level` does not fail client creation: the SDK logs a warning that names
+    the value and uses INFO.
 
     Args:
-        config: The SDK configuration; only `config.log.enable` is read.
+        config: The SDK configuration.
     """
+    sdk_logger.redact(config.token)
     if not config.log.enable:
-        logger.disable(PERMIT_MODULE)
+        sdk_logger.disable()
+        return
+    level_no = _level_no(config.log.level)
+    if level_no is None:
+        sdk_logger.enable(min_level_no=logger.level("INFO").no, label=config.log.label)
+        sdk_logger.warning(
+            f"Unknown log level {config.log.level!r} in the Permit SDK config (log.level), "
+            "so the SDK logs at INFO. Use trace, debug, info, success, warning, error or "
+            "critical, or a level added with loguru's logger.level()."
+        )
+        return
+    sdk_logger.enable(min_level_no=level_no, label=config.log.label)
+
+
+def _level_no(level: str) -> int | None:
+    upper = level.upper()
+    # loguru's level names are case-sensitive: try the name as given first, so a level the
+    # application added in lower case is found, then the upper-case name of a built-in one.
+    for name in (level, _LEVEL_ALIASES.get(upper, upper)):
+        with contextlib.suppress(ValueError):
+            return logger.level(name).no
+    return None