PER-16680: log through an SDK logger that applies the log settings

README.md

@@ -40,6 +40,44 @@ 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.
+  Otherwise a `logger.disable()` your application made for `permit` or one of its modules
+  still applies. When it does undo it, it also undoes your application's own
+  `logger.disable("permit")`, and loguru 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()` builds a new
+  client of the same class, but keeps the process's log settings as they are.
+- The SDK replaces the API key of every client in the process with `[REDACTED]` in the
+  messages it logs, in the error bodies it puts in the exceptions it raises, and in the
+  request headers of the aiohttp response or error those exceptions carry
+  (`original_error`, `response`, the cause), so neither an API or PDP that echoes the key
+  back nor an error tracker that records exceptions exposes it. A key shorter than 12
+  characters is not replaced. The client's start-up line and the PDP error messages show
+  `api_url` and `pdp` without any user name or password in them.
+- `level` also takes a loguru severity number, such as `10` for DEBUG. An unknown name is
+  warned about once per process.
+
 ## 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 error bodies it puts in the
+    exceptions it raises. The client's start-up line logs `api_url` and `pdp` without a user
+    name or password.
+    """
 
     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, without_userinfo
 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):
@@ -92,6 +100,8 @@ def __init__(self, config: PermitConfig) -> None:
             "Authorization": f"Bearer {self._config.token}",
         }
         self._base_url = self._config.pdp
+        # The PDP URL as error messages show it: a proxy URL's user and password left out.
+        self._shown_pdp_url = without_userinfo(self._config.pdp)
 
     @property
     def context_store(self) -> ContextStore:
@@ -172,14 +182,14 @@ async def authorized_users(
                                 f"as the cloud PDP is not compatible with these kinds "
                                 f"of policies.\n"
                                 f"Also, please check your configuration and "
-                                f"make sure it's running at {self._base_url} "
+                                f"make sure it's running at {self._shown_pdp_url} "
                                 f"and accepting requests.\n"
                                 f"Read more about setting up the PDP at {SETUP_PDP_DOCS_LINK}"
                             )
                             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),
@@ -189,7 +199,7 @@ async def authorized_users(
                         )
                         msg = (
                             f"Permit SDK got unexpected status code: {response.status} "
-                            f"from the PDP at {self._base_url}.\nResponse body: {error_body}\n"
+                            f"from the PDP at {self._shown_pdp_url}.\nResponse body: {error_body}\n"
                             f"The PDP is reachable, so this is a rejected request rather than a "
                             f"connectivity problem -- a 401/403 usually means the PDP was started "
                             f"with a different API key than the SDK is using.\n"
@@ -198,7 +208,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,14 +217,14 @@ 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}"
                 )
                 msg = (
                     f"Permit SDK got error: {err}, and cannot connect to the PDP container.\n"
                     f"Please check your configuration and make sure it's running at "
-                    f"{self._base_url} and accepting requests.\n "
+                    f"{self._shown_pdp_url} and accepting requests.\n "
                     f"Read more about setting up the PDP at {SETUP_PDP_DOCS_LINK}"
                 )
                 raise PermitConnectionError(
@@ -314,10 +324,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 +349,7 @@ async def bulk_check(
                     ),
                     err,
                 )
-                logger.error(msg)
+                sdk_logger.error(msg)
                 raise PermitConnectionError(msg, error=err) from err
             return decisions
 
@@ -410,13 +420,13 @@ async def check(
                                 f"as the cloud PDP is not compatible with these kinds "
                                 f"of policies.\n"
                                 f"Also, please check your configuration and make sure it's running "
-                                f"at {self._base_url} and accepting requests.\n"
+                                f"at {self._shown_pdp_url} and accepting requests.\n"
                                 f"Read more about setting up the PDP at {SETUP_PDP_DOCS_LINK}"
                             )
                             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,
@@ -427,7 +437,7 @@ async def check(
                         )
                         msg = (
                             f"Permit SDK got unexpected status code: {response.status} "
-                            f"from the PDP at {self._base_url}.\nResponse body: {error_body}\n"
+                            f"from the PDP at {self._shown_pdp_url}.\nResponse body: {error_body}\n"
                             f"The PDP is reachable, so this is a rejected request rather than a "
                             f"connectivity problem -- a 401/403 usually means the PDP was started "
                             f"with a different API key than the SDK is using.\n"
@@ -436,7 +446,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 +455,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}"
@@ -454,7 +464,7 @@ async def check(
                     f"Permit SDK got error: {err}, \n"
                     f"and cannot connect to the PDP container, please check your configuration "
                     f"and make sure it's "
-                    f"running at {self._base_url} and accepting requests. \n"
+                    f"running at {self._shown_pdp_url} and accepting requests. \n"
                     f"Read more about setting up the PDP at {SETUP_PDP_DOCS_LINK}"
                 )
                 raise PermitConnectionError(
@@ -514,20 +524,20 @@ 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 "
                     f"and make sure it's "
-                    f"running at {self._base_url} and accepting requests. \n"
+                    f"running at {self._shown_pdp_url} and accepting requests. \n"
                     f"Read more about setting up the PDP at {SETUP_PDP_DOCS_LINK}"
                 )
                 raise PermitConnectionError(