From 2a6bd7bdc32c95ea011a1b20806cf443caa8bb0d Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 12:50:15 +0300 Subject: [PATCH 01/16] Stop logging the API key when a client is created With log={"enable": True}, Permit() logged its whole config at DEBUG, token included, and the SDK did not apply log.level, so the API key reached the log whatever level was set (PER-16680). The line now names the API and PDP URLs only. Co-Authored-By: Claude Opus 5.5 --- permit/permit.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/permit/permit.py b/permit/permit.py index 51d6f51f..c0f15178 100644 --- a/permit/permit.py +++ b/permit/permit.py @@ -1,4 +1,3 @@ -import json from collections.abc import Generator from contextlib import contextmanager from typing import Any, Literal @@ -40,8 +39,7 @@ def __init__(self, config: PermitConfig | None = None, **options: Any) -> None: self._elements = ElementsApi(self._config) self._pdp_api = PermitPdpApiClient(self._config) logger.debug( - "Permit SDK initialized with config:\n${}", - json.dumps(self._config.dict(exclude={"api_context"})), + f"Permit SDK initialized: api_url={self._config.api_url}, pdp={self._config.pdp}" ) @property From 39f175fca0af299f452864e678e27f7ccdcbf2c5 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 12:54:06 +0300 Subject: [PATCH 02/16] Redact the API key from every record the SDK logs The SDK's own log lines no longer hold the key, but some records carry text from elsewhere: a PDP error body, an aiohttp error, a context the caller passed to a check. The SDK's records now go through permit.utils.sdk_logger, which replaces the API key of every client created in the process with [REDACTED] before handing the record to loguru, whether or not that client enabled logging (PER-16680). Records are still attributed to the SDK module that logged them, so logger.disable("permit") and the application's sinks see them as before. Co-Authored-By: Claude Opus 5.5 --- permit/api/base.py | 8 ++--- permit/api/context.py | 9 +++--- permit/enforcement/enforcer.py | 24 +++++++------- permit/exceptions.py | 4 +-- permit/logger.py | 7 ++++- permit/permit.py | 6 ++-- permit/utils/sdk_logger.py | 57 ++++++++++++++++++++++++++++++++++ 7 files changed, 88 insertions(+), 27 deletions(-) create mode 100644 permit/utils/sdk_logger.py diff --git a/permit/api/base.py b/permit/api/base.py index def26a01..ea404d50 100644 --- a/permit/api/base.py +++ b/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: diff --git a/permit/api/context.py b/permit/api/context.py index 9d72d835..72d3b5df 100644 --- a/permit/api/context.py +++ b/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 diff --git a/permit/enforcement/enforcer.py b/permit/enforcement/enforcer.py index 119a5d4e..4b65de20 100644 --- a/permit/enforcement/enforcer.py +++ b/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: @@ -179,7 +179,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 +198,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 +207,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 +314,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 +339,7 @@ async def bulk_check( ), err, ) - logger.error(msg) + sdk_logger.error(msg) raise PermitConnectionError(msg, error=err) from err return decisions @@ -416,7 +416,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 +436,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 +445,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,7 +514,7 @@ 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)}" @@ -522,7 +522,7 @@ async def get_user_permissions( 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 " diff --git a/permit/exceptions.py b/permit/exceptions.py index 5a71176e..319b1dac 100644 --- a/permit/exceptions.py +++ b/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 diff --git a/permit/logger.py b/permit/logger.py index d1677f87..3ea44040 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -1,6 +1,7 @@ from loguru import logger from permit.config import PermitConfig +from permit.utils.sdk_logger import sdk_logger PERMIT_MODULE = "permit" @@ -8,8 +9,12 @@ def configure_logger(config: PermitConfig) -> None: """Silence the SDK's loguru output unless the config enables logging. + Whatever the settings, the API key in `config.token` is replaced with `[REDACTED]` in + every record the SDK logs from now on, the records of other clients included. + Args: - config: The SDK configuration; only `config.log.enable` is read. + config: The SDK configuration; `config.log.enable` and `config.token` are read. """ + sdk_logger.redact(config.token) if not config.log.enable: logger.disable(PERMIT_MODULE) diff --git a/permit/permit.py b/permit/permit.py index c0f15178..b86302a5 100644 --- a/permit/permit.py +++ b/permit/permit.py @@ -2,7 +2,6 @@ from contextlib import contextmanager from typing import Any, Literal -from loguru import logger from typing_extensions import Self from permit.api.api_client import PermitApiClient @@ -19,6 +18,7 @@ from permit.logger import configure_logger from permit.pdp_api.pdp_api_client import PermitPdpApiClient from permit.utils.context import Context +from permit.utils.sdk_logger import sdk_logger class Permit: @@ -38,7 +38,7 @@ def __init__(self, config: PermitConfig | None = None, **options: Any) -> None: self._api = PermitApiClient(self._config) self._elements = ElementsApi(self._config) self._pdp_api = PermitPdpApiClient(self._config) - logger.debug( + sdk_logger.debug( f"Permit SDK initialized: api_url={self._config.api_url}, pdp={self._config.pdp}" ) @@ -79,7 +79,7 @@ def wait_for_sync( https://docs.permit.io/how-to/manage-data/local-facts-uploader """ if not self._config.proxy_facts_via_pdp: - logger.warning( + sdk_logger.warning( "Tried to wait for synced facts but proxy_facts_via_pdp is disabled, ignoring..." ) yield self diff --git a/permit/utils/sdk_logger.py b/permit/utils/sdk_logger.py new file mode 100644 index 00000000..56a13e82 --- /dev/null +++ b/permit/utils/sdk_logger.py @@ -0,0 +1,57 @@ +import threading + +from loguru import logger + +REDACTED = "[REDACTED]" + + +class SdkLogger: + """Logs the SDK's own records to loguru's logger, without the API keys in them. + + Each record reaches loguru from the SDK module that logged it, so + `logger.disable("permit")`, `logger.enable("permit")` and the application's sinks treat + it as a record of that module. On the way, this replaces every registered API key with + `[REDACTED]`. + + The registered keys are process-wide, like loguru's logger. + """ + + def __init__(self) -> None: + self._secrets_lock = threading.Lock() + # Replaced, never mutated, so a thread that logs while another registers a secret + # reads either the old set or the new one. + self._secrets: frozenset[str] = frozenset() + + def redact(self, secret: str) -> None: + """Replace `secret` with `[REDACTED]` in every record logged from now on. + + Args: + secret: A credential, such as an API key. An empty string is ignored. + """ + if not secret: + return + with self._secrets_lock: + self._secrets |= {secret} + + def debug(self, message: str) -> None: + """Log `message` with severity DEBUG.""" + self._log("DEBUG", message) + + def warning(self, message: str) -> None: + """Log `message` with severity WARNING.""" + self._log("WARNING", message) + + def error(self, message: str) -> None: + """Log `message` with severity ERROR.""" + self._log("ERROR", message) + + def _log(self, level: str, message: str) -> None: + for secret in self._secrets: + message = message.replace(secret, REDACTED) + # depth=2 skips this method and the one that called it, so loguru attributes the + # record to the SDK module that logged it. The message goes without arguments, so + # loguru does not call str.format on it and braces in it are kept as they are. + logger.opt(depth=2).log(level, message) + + +sdk_logger = SdkLogger() From 074cf96f2676710daf7866efc5d5c67d686d113a Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 12:51:28 +0300 Subject: [PATCH 03/16] Apply the log level and label to the SDK's records LoggerConfig's level and label had no effect (PER-16680): loguru's default sink printed every SDK record from DEBUG up, unlabelled. The SDK still adds no sink and leaves the application's sinks and levels alone. Instead, with log.enable True: - level drops the SDK's records below it before they reach any sink. Names are loguru's, in any case, plus warn and fatal. An unknown name raises ValueError when the client is created. - label is put in square brackets before every SDK message. - logger.enable("permit") is called, so a client that enables logging after one that disabled it is no longer silenced. log_as_json stays unapplied: loguru serializes per sink, and a JSON sink of the SDK's own would print every record a second time through loguru's default sink or the application's. The settings are process-wide, as loguru's logger is. With log.enable False nothing changes: the SDK calls logger.disable("permit") and reads no other setting. Co-Authored-By: Claude Opus 5.5 --- permit/logger.py | 44 ++++++++++++++++++++++++++++++++++---- permit/utils/sdk_logger.py | 26 ++++++++++++++++++---- 2 files changed, 62 insertions(+), 8 deletions(-) diff --git a/permit/logger.py b/permit/logger.py index 3ea44040..09bd4fb5 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -5,16 +5,52 @@ 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 calls + `logger.enable("permit")`. + - `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, with + `logger.add(..., serialize=True)`. - Whatever the settings, the API key in `config.token` is replaced with `[REDACTED]` in - every record the SDK logs from now on, the records of other clients included. + The API key in `config.token` is replaced with `[REDACTED]` in every record the SDK + logs, whatever the settings. Args: - config: The SDK configuration; `config.log.enable` and `config.token` are read. + config: The SDK configuration. + + Raises: + ValueError: If `log.enable` is True and `log.level` is not the name of a loguru level. """ sdk_logger.redact(config.token) if not config.log.enable: logger.disable(PERMIT_MODULE) + return + sdk_logger.configure(min_level_no=_level_no(config.log.level), label=config.log.label) + logger.enable(PERMIT_MODULE) + + +def _level_no(level: str) -> int: + name = level.upper() + name = _LEVEL_ALIASES.get(name, name) + try: + return logger.level(name).no + except ValueError: + msg = ( + f"Invalid log level {level!r} in the Permit SDK config (log.level): use trace, " + "debug, info, success, warning, error or critical, or a level added with " + "loguru's logger.level()." + ) + raise ValueError(msg) from None diff --git a/permit/utils/sdk_logger.py b/permit/utils/sdk_logger.py index 56a13e82..58086c88 100644 --- a/permit/utils/sdk_logger.py +++ b/permit/utils/sdk_logger.py @@ -6,22 +6,36 @@ class SdkLogger: - """Logs the SDK's own records to loguru's logger, without the API keys in them. + """Logs the SDK's own records to loguru's logger, applying the SDK's `log` settings. Each record reaches loguru from the SDK module that logged it, so `logger.disable("permit")`, `logger.enable("permit")` and the application's sinks treat - it as a record of that module. On the way, this replaces every registered API key with - `[REDACTED]`. + it as a record of that module. On the way, this drops records below the minimum + severity, replaces every registered API key with `[REDACTED]` and prefixes the message + with the label. - The registered keys are process-wide, like loguru's logger. + Its settings are process-wide, like loguru's logger. Until `configure` is called, it + keeps every record and adds no label. """ def __init__(self) -> None: + self._min_level_no = 0 + self._label = "" self._secrets_lock = threading.Lock() # Replaced, never mutated, so a thread that logs while another registers a secret # reads either the old set or the new one. self._secrets: frozenset[str] = frozenset() + def configure(self, *, min_level_no: int, label: str) -> None: + """Set the minimum severity of the records to keep and the label to prefix them with. + + Args: + min_level_no: The loguru severity number below which records are dropped. + label: The text put in brackets before each message; an empty string adds none. + """ + self._min_level_no = min_level_no + self._label = label + def redact(self, secret: str) -> None: """Replace `secret` with `[REDACTED]` in every record logged from now on. @@ -46,8 +60,12 @@ def error(self, message: str) -> None: self._log("ERROR", message) def _log(self, level: str, message: str) -> None: + if logger.level(level).no < self._min_level_no: + return for secret in self._secrets: message = message.replace(secret, REDACTED) + if self._label: + message = f"[{self._label}] {message}" # depth=2 skips this method and the one that called it, so loguru attributes the # record to the SDK module that logged it. The message goes without arguments, so # loguru does not call str.format on it and braces in it are kept as they are. From 9965fedab854d81ffd057329c9cb94eb2123b5ad Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 12:51:46 +0300 Subject: [PATCH 04/16] Document what each log option does LoggerConfig's descriptions said each option set something on "the Permit SDK Logger", which did not exist. They and a new Logging section in the README now say where the SDK's records go, what enable, level and label do, that json is not applied and how to get JSON from a loguru sink, that the settings are process-wide, and that no record holds the API key (PER-16680). Co-Authored-By: Claude Opus 5.5 --- README.md | 20 ++++++++++++++++++++ permit/config.py | 27 ++++++++++++++++++++++----- 2 files changed, 42 insertions(+), 5 deletions(-) diff --git a/README.md b/README.md index e249ce14..56e167f3 100644 --- a/README.md +++ b/README.md @@ -40,6 +40,26 @@ 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="", 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. +- `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. +- `label` (default `"Permit"`) is put in square brackets before every message the SDK logs. +- `json` is not applied: for JSON output, add a sink with `logger.add(sys.stderr, serialize=True)`. +- 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. +- No record the SDK logs contains the API key. + ## Deprecations A future major release, permit 4.0, will remove the following. They still work in 3.x, and diff --git a/permit/config.py b/permit/config.py index 7a42f941..f842ee1d 100644 --- a/permit/config.py +++ b/permit/config.py @@ -13,22 +13,39 @@ 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. No record the SDK logs + contains the API key: it is replaced with `[REDACTED]`. + """ 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 calls logger.enable('permit').", ) 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; a name loguru does not know raises ValueError when the " + "client is created.", ) 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, add a sink with logger.add(..., serialize=True).", ) From 457ca087e8e585097eee3061e42bb8eff8c2fe5c Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 12:52:11 +0300 Subject: [PATCH 05/16] Test that the SDK never logs its API key and applies log settings Offline tests for PER-16680, with loguru sinks added the way an application adds them: a stderr sink in loguru's default format and a JSON sink, both at DEBUG. For the async and the blocking client, at level debug, info and unset, with json on and off, they go through every kind of record the SDK logs and find neither the API key nor a [REDACTED] marker. They also check that a key a PDP echoes back is redacted, that level drops the SDK's records and no others, that label prefixes every SDK message, that json leaves the format to the sinks, that a disabled client logs nothing, that the client created last decides, and that creating 40 clients adds no sink. Each test starts from a fresh SdkLogger and puts loguru's permit switch back the way it found it. Co-Authored-By: Claude Opus 5.5 --- tests/test_fix_logging.py | 433 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 433 insertions(+) create mode 100644 tests/test_fix_logging.py diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py new file mode 100644 index 00000000..2a520e55 --- /dev/null +++ b/tests/test_fix_logging.py @@ -0,0 +1,433 @@ +"""Offline tests for the SDK's logging (PER-16680). + +The SDK logs through loguru's process-wide logger and adds no sink of its own. These tests +add sinks the way an application does, and read what reached them: a text sink on stderr in +loguru's default format, read through capsys, and a serialized (JSON) sink. Every request is +served by a local pytest_httpserver. +""" + +import json +import sys +import types +from collections.abc import Iterator +from dataclasses import dataclass, field +from typing import Any + +import pytest +from loguru import logger +from pytest_httpserver import HTTPServer +from werkzeug import Request, Response + +from permit import Permit, PermitConfig +from permit.enforcement.enforcer import CheckQuery +from permit.exceptions import PermitConnectionError +from permit.sync import Permit as SyncPermit +from permit.utils.sdk_logger import REDACTED, SdkLogger, sdk_logger + +SENTINEL = "permit_key_SENTINEL_9f8e7d6c5b4a39281706f5e4d3c2b1a0" +ORG_ID = "00000000-0000-4000-8000-00000000000a" +PROJECT_ID = "00000000-0000-4000-8000-00000000000b" +ENV_ID = "00000000-0000-4000-8000-00000000000c" +USERS = f"/v2/facts/{PROJECT_ID}/{ENV_ID}/users" +WAIT_FOR_SYNC_WARNING = "Tried to wait for synced facts" + + +def _probe() -> None: + logger.log("TRACE", "permit logging probe") + + +def _permit_records_enabled() -> bool: + """Whether loguru lets the records of the permit package through right now. + + loguru has no getter for this, so log a TRACE record from a function whose module name + is in the package, and see whether a sink receives it. + """ + received: list[str] = [] + probe_module = "permit._logging_probe" + sink_id = logger.add( + received.append, level="TRACE", filter=lambda record: record["name"] == probe_module + ) + try: + types.FunctionType(_probe.__code__, {"__name__": probe_module, "logger": logger})() + finally: + logger.remove(sink_id) + return bool(received) + + +@pytest.fixture(autouse=True) +def isolated_logging() -> Iterator[None]: + """Start from a fresh SdkLogger, and put both it and loguru's permit switch back after.""" + was_enabled = _permit_records_enabled() + saved = vars(sdk_logger).copy() + vars(sdk_logger).update(vars(SdkLogger())) + yield + vars(sdk_logger).update(saved) + if was_enabled: + logger.enable("permit") + else: + logger.disable("permit") + + +@dataclass +class AppSinks: + """What the application's own loguru sinks received during a test.""" + + capsys: pytest.CaptureFixture[str] + json_lines: list[str] = field(default_factory=list) + _stderr: str = "" + + def stderr(self) -> str: + captured = self.capsys.readouterr() + assert captured.out == "" + self._stderr += captured.err + return self._stderr + + def everything(self) -> str: + return self.stderr() + "".join(self.json_lines) + + def records(self) -> list[dict[str, Any]]: + return [json.loads(line)["record"] for line in self.json_lines] + + def sdk_records(self) -> list[dict[str, Any]]: + return [ + record + for record in self.records() + if record["name"] == "permit" or record["name"].startswith("permit.") + ] + + def sdk_levels(self) -> set[str]: + return {record["level"]["name"] for record in self.sdk_records()} + + def wait_for_sync_warnings(self) -> list[dict[str, Any]]: + """The records of the warning `wait_for_sync` logs when facts are not proxied.""" + return [ + record for record in self.sdk_records() if WAIT_FOR_SYNC_WARNING in record["message"] + ] + + +def write_to_stderr(message: str) -> None: + """Write to the sys.stderr of the moment: capsys replaces it in each phase of a test.""" + sys.stderr.write(message) + + +@pytest.fixture +def app_sinks(capsys: pytest.CaptureFixture[str]) -> Iterator[AppSinks]: + """A stderr sink in loguru's default format and a JSON sink, both at DEBUG.""" + sinks = AppSinks(capsys) + sink_ids = [ + logger.add(write_to_stderr, level="DEBUG"), + logger.add(sinks.json_lines.append, level="DEBUG", serialize=True), + ] + yield sinks + for sink_id in sink_ids: + logger.remove(sink_id) + + +def make_config(httpserver: HTTPServer, *, token: str = SENTINEL, **log: Any) -> PermitConfig: + url = httpserver.url_for("").rstrip("/") + return PermitConfig(token=token, api_url=url, pdp=url, log=log) + + +def serve(httpserver: HTTPServer) -> None: + """Answer the requests `use_async_client` and `use_sync_client` make.""" + httpserver.expect_request("/v2/api-key/scope", method="GET").respond_with_json( + {"organization_id": ORG_ID, "project_id": PROJECT_ID, "environment_id": ENV_ID} + ) + httpserver.expect_request(USERS, method="GET").respond_with_json( + {"data": [], "total_count": 0, "page_count": 0} + ) + # Not JSON, so reading the response raises an aiohttp error, which the SDK logs. + httpserver.expect_request(f"{USERS}/user-1", method="GET").respond_with_data( + "not json", content_type="text/plain" + ) + httpserver.expect_request("/allowed", method="POST").respond_with_json({"allow": True}) + httpserver.expect_request("/allowed/bulk", method="POST").respond_with_data( + "PDP failure", status=500 + ) + + +BULK: list[CheckQuery] = [{"user": "user-1", "action": "read", "resource": "document"}] + + +async def use_async_client(permit: Permit) -> None: + """Go through every kind of record the SDK logs: DEBUG, WARNING and ERROR.""" + with permit.wait_for_sync(): + pass + assert await permit.check("user-1", "read", "document") + await permit.api.users.list() + with pytest.raises(PermitConnectionError): + await permit.api.users.get("user-1") + with pytest.raises(PermitConnectionError): + await permit.bulk_check(BULK) + + +def use_sync_client(permit: SyncPermit) -> None: + """The blocking twin of `use_async_client`.""" + with permit.wait_for_sync(): + pass + assert permit.check("user-1", "read", "document") + permit.api.users.list() + with pytest.raises(PermitConnectionError): + permit.api.users.get("user-1") + with pytest.raises(PermitConnectionError): + permit.bulk_check(BULK) + + +def assert_api_key_not_logged( + httpserver: HTTPServer, app_sinks: AppSinks, expected_levels: set[str] +) -> None: + # The key was in use: every request carried it. + sent = {request.headers.get("Authorization") for request, _ in httpserver.log} + assert sent == {f"Bearer {SENTINEL}"} + output = app_sinks.everything() + assert SENTINEL not in output + # Nothing was redacted either: no SDK record held the key in the first place. + assert REDACTED not in output + assert app_sinks.sdk_levels() == expected_levels + # Each SDK record is one line on stderr, in the sink's format. + assert app_sinks.stderr().count(" | permit.") == len(app_sinks.sdk_records()) + + +LOG_LEVELS = [ + pytest.param({"level": "debug"}, {"DEBUG", "WARNING", "ERROR"}, id="debug"), + pytest.param({"level": "info"}, {"WARNING", "ERROR"}, id="info"), + pytest.param({}, {"WARNING", "ERROR"}, id="unset"), +] +AS_JSON = [pytest.param(True, id="json"), pytest.param(False, id="text")] + + +@pytest.mark.parametrize(("log", "expected_levels"), LOG_LEVELS) +@pytest.mark.parametrize("as_json", AS_JSON) +async def test_async_client_never_logs_the_api_key( + httpserver: HTTPServer, + app_sinks: AppSinks, + log: dict[str, str], + expected_levels: set[str], + *, + as_json: bool, +) -> None: + serve(httpserver) + + await use_async_client(Permit(make_config(httpserver, enable=True, json=as_json, **log))) + + assert_api_key_not_logged(httpserver, app_sinks, expected_levels) + + +@pytest.mark.parametrize(("log", "expected_levels"), LOG_LEVELS) +@pytest.mark.parametrize("as_json", AS_JSON) +def test_sync_client_never_logs_the_api_key( + httpserver: HTTPServer, + app_sinks: AppSinks, + log: dict[str, str], + expected_levels: set[str], + *, + as_json: bool, +) -> None: + serve(httpserver) + + use_sync_client(SyncPermit(make_config(httpserver, enable=True, json=as_json, **log))) + + assert_api_key_not_logged(httpserver, app_sinks, expected_levels) + + +@pytest.mark.parametrize("enabled_by", ["config", "application"]) +async def test_an_api_key_the_pdp_echoes_back_is_redacted( + httpserver: HTTPServer, app_sinks: AppSinks, enabled_by: str +) -> None: + def echo_the_key(request: Request) -> Response: + return Response(f"rejected key: {request.headers['Authorization']}", status=403) + + httpserver.expect_request("/allowed", method="POST").respond_with_handler(echo_the_key) + if enabled_by == "config": + permit = Permit(make_config(httpserver, enable=True)) + else: + # A client created with logging disabled, whose records the application turns on. + permit = Permit(make_config(httpserver)) + logger.enable("permit") + + with pytest.raises(PermitConnectionError): + await permit.check("user-1", "read", "document") + + [record] = [record for record in app_sinks.sdk_records() if record["level"]["name"] == "ERROR"] + assert f"rejected key: Bearer {REDACTED}" in record["message"] + assert SENTINEL not in app_sinks.everything() + + +@pytest.mark.parametrize( + ("log", "expected_levels"), + [ + pytest.param({"level": "trace"}, {"DEBUG", "WARNING", "ERROR"}, id="trace"), + pytest.param({"level": "debug"}, {"DEBUG", "WARNING", "ERROR"}, id="debug"), + pytest.param({}, {"WARNING", "ERROR"}, id="unset"), + pytest.param({"level": "INFO"}, {"WARNING", "ERROR"}, id="INFO"), + pytest.param({"level": "warning"}, {"WARNING", "ERROR"}, id="warning"), + pytest.param({"level": "warn"}, {"WARNING", "ERROR"}, id="warn"), + pytest.param({"level": "error"}, {"ERROR"}, id="error"), + pytest.param({"level": "critical"}, set(), id="critical"), + ], +) +async def test_level_drops_the_sdk_records_below_it( + httpserver: HTTPServer, app_sinks: AppSinks, log: dict[str, str], expected_levels: set[str] +) -> None: + serve(httpserver) + + await use_async_client(Permit(make_config(httpserver, enable=True, **log))) + logger.debug("an application record") + + assert app_sinks.sdk_levels() == expected_levels + # The application's own records are not the SDK's to filter. + assert "an application record" in [record["message"] for record in app_sinks.records()] + + +def test_an_unknown_level_fails_when_the_client_is_created(httpserver: HTTPServer) -> None: + with pytest.raises(ValueError, match=r"Invalid log level 'verbose'"): + SyncPermit(make_config(httpserver, enable=True, level="verbose")) + + +@pytest.mark.parametrize( + ("log", "prefix"), + [ + pytest.param({}, "[Permit] ", id="default"), + pytest.param({"label": "acme-authz"}, "[acme-authz] ", id="custom"), + ], +) +async def test_label_prefixes_every_sdk_message( + httpserver: HTTPServer, app_sinks: AppSinks, log: dict[str, str], prefix: str +) -> None: + serve(httpserver) + + await use_async_client(Permit(make_config(httpserver, enable=True, level="debug", **log))) + + messages = [record["message"] for record in app_sinks.sdk_records()] + assert len(messages) > 3 + assert [message for message in messages if not message.startswith(prefix)] == [] + assert f"{prefix}{WAIT_FOR_SYNC_WARNING}" in app_sinks.stderr() + + +def test_an_empty_label_adds_no_prefix(httpserver: HTTPServer, app_sinks: AppSinks) -> None: + with SyncPermit(make_config(httpserver, enable=True, label="")).wait_for_sync(): + pass + + [record] = app_sinks.wait_for_sync_warnings() + assert record["message"].startswith(WAIT_FOR_SYNC_WARNING) + + +def test_an_empty_api_key_redacts_nothing(httpserver: HTTPServer, app_sinks: AppSinks) -> None: + with SyncPermit(make_config(httpserver, token="", enable=True)).wait_for_sync(): + pass + + [record] = app_sinks.wait_for_sync_warnings() + assert ( + record["message"] + == f"[Permit] {WAIT_FOR_SYNC_WARNING} but proxy_facts_via_pdp is disabled, ignoring..." + ) + + +def test_records_name_the_sdk_module_that_logged_them( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + with SyncPermit(make_config(httpserver, enable=True)).wait_for_sync(): + pass + + [record] = app_sinks.wait_for_sync_warnings() + assert (record["name"], record["function"]) == ("permit.permit", "wait_for_sync") + assert "| permit.permit:wait_for_sync:" in app_sinks.stderr() + + +@pytest.mark.parametrize("as_json", AS_JSON) +def test_log_as_json_leaves_the_format_to_the_application_sinks( + httpserver: HTTPServer, app_sinks: AppSinks, *, as_json: bool +) -> None: + with SyncPermit(make_config(httpserver, enable=True, json=as_json)).wait_for_sync(): + pass + + # One text line in the stderr sink and one JSON line in the JSON sink: the SDK + # neither adds a JSON sink of its own nor changes the application's. + [line] = [line for line in app_sinks.stderr().splitlines() if WAIT_FOR_SYNC_WARNING in line] + assert "| WARNING | permit.permit:wait_for_sync:" in line + assert len(app_sinks.wait_for_sync_warnings()) == 1 + + +DISABLED = [ + pytest.param({}, id="unset"), + pytest.param({"enable": False}, id="false"), + pytest.param( + {"enable": False, "level": "debug", "label": "x", "json": True}, id="false-with-options" + ), + pytest.param({"enable": False, "level": "not-a-level"}, id="false-unknown-level"), +] + + +@pytest.mark.parametrize("log", DISABLED) +async def test_async_client_with_logging_disabled_logs_nothing( + httpserver: HTTPServer, app_sinks: AppSinks, log: dict[str, Any] +) -> None: + serve(httpserver) + + await use_async_client(Permit(make_config(httpserver, **log))) + + assert app_sinks.everything() == "" + + +@pytest.mark.parametrize("log", DISABLED) +def test_sync_client_with_logging_disabled_logs_nothing( + httpserver: HTTPServer, app_sinks: AppSinks, log: dict[str, Any] +) -> None: + serve(httpserver) + + use_sync_client(SyncPermit(make_config(httpserver, **log))) + + assert app_sinks.everything() == "" + + +def test_the_client_created_last_decides_whether_the_sdk_logs( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + SyncPermit(make_config(httpserver)) + enabled = SyncPermit(make_config(httpserver, enable=True)) + with enabled.wait_for_sync(): + pass + assert len(app_sinks.wait_for_sync_warnings()) == 1 + + SyncPermit(make_config(httpserver)) + with enabled.wait_for_sync(): + pass + assert len(app_sinks.wait_for_sync_warnings()) == 1 + + +def test_the_application_can_still_turn_the_sdk_records_on_itself( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + httpserver.expect_request("/allowed", method="POST").respond_with_json({"allow": True}) + permit = SyncPermit(make_config(httpserver)) + + logger.enable("permit") + assert permit.check("user-1", "read", "document") + + # No client enabled logging, so no level or label applies: the records are as before. + [record] = app_sinks.sdk_records() + assert record["level"]["name"] == "DEBUG" + assert record["message"].startswith("permit.check() response:") + + +def _next_handler_id() -> int: + """The id loguru gives the next sink: each `logger.add` takes the next one.""" + sink_id = logger.add(lambda _: None) + logger.remove(sink_id) + return sink_id + + +def test_creating_many_clients_adds_no_sinks(httpserver: HTTPServer, app_sinks: AppSinks) -> None: + first_free_id = _next_handler_id() + + clients = [ + client_class(make_config(httpserver, enable=True, json=True, label=f"client-{index}")) + for index in range(20) + for client_class in (Permit, SyncPermit) + ] + + assert _next_handler_id() == first_free_id + 1 + with clients[-1].wait_for_sync(): + pass + assert len(app_sinks.wait_for_sync_warnings()) == 1 + assert app_sinks.stderr().count(WAIT_FOR_SYNC_WARNING) == 1 From eaf1722c887df590f82afc74c0531dec9cfb089c Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:00:47 +0300 Subject: [PATCH 06/16] Accept a lower-case log level the application added to loguru loguru's level names are case-sensitive, and log.level was looked up only in upper case, so a level such as logger.level("audit", no=35) raised ValueError although the error message offers levels added with logger.level(). Try the name as given first, then the upper-case name. Co-Authored-By: Claude Opus 5.5 --- permit/logger.py | 25 ++++++++++--------- tests/test_fix_logging.py | 52 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 66 insertions(+), 11 deletions(-) diff --git a/permit/logger.py b/permit/logger.py index 09bd4fb5..d0fc4c8a 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -1,3 +1,5 @@ +import contextlib + from loguru import logger from permit.config import PermitConfig @@ -43,14 +45,15 @@ def configure_logger(config: PermitConfig) -> None: def _level_no(level: str) -> int: - name = level.upper() - name = _LEVEL_ALIASES.get(name, name) - try: - return logger.level(name).no - except ValueError: - msg = ( - f"Invalid log level {level!r} in the Permit SDK config (log.level): use trace, " - "debug, info, success, warning, error or critical, or a level added with " - "loguru's logger.level()." - ) - raise ValueError(msg) from 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 + msg = ( + f"Invalid log level {level!r} in the Permit SDK config (log.level): use trace, " + "debug, info, success, warning, error or critical, or a level added with " + "loguru's logger.level()." + ) + raise ValueError(msg) diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 2a520e55..50c98b8d 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -7,10 +7,12 @@ """ import json +import subprocess import sys import types from collections.abc import Iterator from dataclasses import dataclass, field +from pathlib import Path from typing import Any import pytest @@ -284,6 +286,56 @@ def test_an_unknown_level_fails_when_the_client_is_created(httpserver: HTTPServe SyncPermit(make_config(httpserver, enable=True, level="verbose")) +# loguru cannot remove a level once added, so this application runs in its own process. +CUSTOM_LEVEL_APP = f""" +import sys + +from loguru import logger + +from permit import PermitConnectionError +from permit.sync import Permit + +logger.remove() +logger.add(sys.stdout, serialize=True) +logger.level("audit", no=35) +url = sys.argv[1] +permit = Permit( + token="{SENTINEL}", api_url=url, pdp=url, log={{"enable": True, "level": "audit"}} +) +with permit.wait_for_sync(): + pass +try: + permit.check("user-1", "read", "document") +except PermitConnectionError: + pass +""" + + +def test_level_accepts_a_level_the_application_added( + httpserver: HTTPServer, tmp_path: Path +) -> None: + httpserver.expect_request("/allowed", method="POST").respond_with_data( + "PDP failure", status=500 + ) + app = tmp_path / "app.py" + app.write_text(CUSTOM_LEVEL_APP) + + result = subprocess.run( + [sys.executable, str(app), httpserver.url_for("").rstrip("/")], + capture_output=True, + text=True, + timeout=120, + check=False, + ) + + assert result.returncode == 0, result.stderr + # "audit" (35) sits between WARNING (30) and ERROR (40): only the ERROR record is kept. + [record] = [json.loads(line)["record"] for line in result.stdout.splitlines()] + assert record["level"]["name"] == "ERROR" + assert record["message"].startswith("[Permit] error in permit.check(") + assert SENTINEL not in result.stdout + result.stderr + + @pytest.mark.parametrize( ("log", "prefix"), [ From 0a0cbbc951afa935464852dacf523e58495c16a2 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:00:58 +0300 Subject: [PATCH 07/16] Say in the README what the log level hides and when it raises Co-Authored-By: Claude Opus 5.5 --- README.md | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/README.md b/README.md index 56e167f3..1c63fadb 100644 --- a/README.md +++ b/README.md @@ -52,7 +52,9 @@ permit = Permit(token="", 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. - `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. + 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`, a level name loguru + does not know raises `ValueError` when the client is created. - `label` (default `"Permit"`) is put in square brackets before every message the SDK logs. - `json` is not applied: for JSON output, add a sink with `logger.add(sys.stderr, serialize=True)`. - loguru's logger is process-wide, so these settings are too: the client created last From ef40ecdc39c73716ad987a82e4cc44fbd3354f8a Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:23:28 +0300 Subject: [PATCH 08/16] Hide the API key from PermitConfig's repr An unknown log level now raises ValueError while the client is created. An application that logs that failure with loguru's logger.exception (diagnose=True by default) printed the config's repr from the SDK's frames, and with it the API key. repr=False keeps the token out of repr() and str() of the config; the field itself is unchanged. Co-Authored-By: Claude Opus 5.5 --- permit/config.py | 3 +++ tests/test_fix_logging.py | 23 +++++++++++++++++++++++ 2 files changed, 26 insertions(+) diff --git a/permit/config.py b/permit/config.py index f842ee1d..2ffc9a99 100644 --- a/permit/config.py +++ b/permit/config.py @@ -71,8 +71,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.", ) diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 50c98b8d..636f8786 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -286,6 +286,29 @@ def test_an_unknown_level_fails_when_the_client_is_created(httpserver: HTTPServe SyncPermit(make_config(httpserver, enable=True, level="verbose")) +def test_the_traceback_of_a_failed_client_creation_hides_the_api_key( + httpserver: HTTPServer, +) -> None: + lines: list[str] = [] + # diagnose=True, loguru's default, prints the value of each name on every line of the + # traceback, and the SDK's frames pass the config around. + sink_id = logger.add(lines.append, diagnose=True, backtrace=True) + config = make_config(httpserver, enable=True, level="verbose") + try: + try: + SyncPermit(config) + except ValueError: + logger.exception("the application could not start") + finally: + logger.remove(sink_id) + + output = "".join(lines) + assert "configure_logger(" in output + assert "PermitConfig(pdp=" in output + assert SENTINEL not in output + assert SENTINEL not in str(config) + + # loguru cannot remove a level once added, so this application runs in its own process. CUSTOM_LEVEL_APP = f""" import sys From 1bb2a3235b00338aaab47785d51dfd6101bb3f14 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:35:33 +0300 Subject: [PATCH 09/16] Redact the longest registered API key first The keys were kept in a frozenset and replaced in its iteration order, which depends on the hash seed. When a key that is a prefix of another was replaced first, the rest of the longer key stayed in the record. Keep the keys in a tuple sorted longest first, and move the replacement into SdkLogger.scrub(). Co-Authored-By: Claude Opus 5.5 --- permit/utils/sdk_logger.py | 27 +++++++++++++++++++++------ tests/test_fix_logging.py | 25 ++++++++++++++++++++++--- 2 files changed, 43 insertions(+), 9 deletions(-) diff --git a/permit/utils/sdk_logger.py b/permit/utils/sdk_logger.py index 58086c88..5b3a11ed 100644 --- a/permit/utils/sdk_logger.py +++ b/permit/utils/sdk_logger.py @@ -22,9 +22,11 @@ def __init__(self) -> None: self._min_level_no = 0 self._label = "" self._secrets_lock = threading.Lock() - # Replaced, never mutated, so a thread that logs while another registers a secret - # reads either the old set or the new one. - self._secrets: frozenset[str] = frozenset() + # Longest first: where one secret contains another, such as a key and a prefix of + # it, the whole of the longer one is replaced, not just the shorter part. Replaced, + # never mutated, so a thread that logs while another registers a secret reads + # either the old tuple or the new one. + self._secrets: tuple[str, ...] = () def configure(self, *, min_level_no: int, label: str) -> None: """Set the minimum severity of the records to keep and the label to prefix them with. @@ -45,7 +47,21 @@ def redact(self, secret: str) -> None: if not secret: return with self._secrets_lock: - self._secrets |= {secret} + if secret not in self._secrets: + self._secrets = tuple(sorted((*self._secrets, secret), key=len, reverse=True)) + + def scrub(self, text: str) -> str: + """Return `text` with every registered secret replaced with `[REDACTED]`. + + Args: + text: Any text the SDK logs or puts in an exception. + + Returns: + The text without any registered secret. + """ + for secret in self._secrets: + text = text.replace(secret, REDACTED) + return text def debug(self, message: str) -> None: """Log `message` with severity DEBUG.""" @@ -62,8 +78,7 @@ def error(self, message: str) -> None: def _log(self, level: str, message: str) -> None: if logger.level(level).no < self._min_level_no: return - for secret in self._secrets: - message = message.replace(secret, REDACTED) + message = self.scrub(message) if self._label: message = f"[{self._label}] {message}" # depth=2 skips this method and the one that called it, so loguru attributes the diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 636f8786..8d663e72 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -232,13 +232,15 @@ def test_sync_client_never_logs_the_api_key( assert_api_key_not_logged(httpserver, app_sinks, expected_levels) +def echo_the_key(request: Request) -> Response: + """A PDP that rejects the request and echoes the API key it was sent.""" + return Response(f"rejected key: {request.headers['Authorization']}", status=403) + + @pytest.mark.parametrize("enabled_by", ["config", "application"]) async def test_an_api_key_the_pdp_echoes_back_is_redacted( httpserver: HTTPServer, app_sinks: AppSinks, enabled_by: str ) -> None: - def echo_the_key(request: Request) -> Response: - return Response(f"rejected key: {request.headers['Authorization']}", status=403) - httpserver.expect_request("/allowed", method="POST").respond_with_handler(echo_the_key) if enabled_by == "config": permit = Permit(make_config(httpserver, enable=True)) @@ -255,6 +257,23 @@ def echo_the_key(request: Request) -> Response: assert SENTINEL not in app_sinks.everything() +async def test_a_key_is_redacted_whole_when_another_key_is_a_prefix_of_it( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + # Clients created earlier in the process with keys the real key starts with. + for length in range(len("permit_key_"), len(SENTINEL), 2): + Permit(make_config(httpserver, token=SENTINEL[:length], enable=True)) + httpserver.expect_request("/allowed", method="POST").respond_with_handler(echo_the_key) + permit = Permit(make_config(httpserver, enable=True)) + + with pytest.raises(PermitConnectionError): + await permit.check("user-1", "read", "document") + + [record] = [record for record in app_sinks.sdk_records() if record["level"]["name"] == "ERROR"] + assert record["message"].endswith(f"rejected key: Bearer {REDACTED}") + assert SENTINEL[-8:] not in app_sinks.everything() + + @pytest.mark.parametrize( ("log", "expected_levels"), [ From e9100d2ce75c9dce38cd0509316c93e540a43108 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:36:09 +0300 Subject: [PATCH 10/16] Also redact the API key without surrounding whitespace A key read from a file or an environment variable may end with a space. aiohttp sends it, and a PDP that echoes the key back returns it trimmed, so the exact-match replacement missed it. Register the trimmed key as well, and ignore a key that is only whitespace, which would otherwise replace every space in the SDK's messages. Co-Authored-By: Claude Opus 5.5 --- permit/utils/sdk_logger.py | 15 +++++++++++---- tests/test_fix_logging.py | 21 +++++++++++++++++++-- 2 files changed, 30 insertions(+), 6 deletions(-) diff --git a/permit/utils/sdk_logger.py b/permit/utils/sdk_logger.py index 5b3a11ed..72d70787 100644 --- a/permit/utils/sdk_logger.py +++ b/permit/utils/sdk_logger.py @@ -41,14 +41,21 @@ def configure(self, *, min_level_no: int, label: str) -> None: def redact(self, secret: str) -> None: """Replace `secret` with `[REDACTED]` in every record logged from now on. + The secret without its leading and trailing whitespace is replaced too: a key read + from a file or an environment variable may end with a space, which an HTTP server + that echoes the key back has stripped. + Args: - secret: A credential, such as an API key. An empty string is ignored. + secret: A credential, such as an API key. A secret that is empty or only + whitespace is ignored. """ - if not secret: + trimmed = secret.strip() + if not trimmed: return with self._secrets_lock: - if secret not in self._secrets: - self._secrets = tuple(sorted((*self._secrets, secret), key=len, reverse=True)) + new = {secret, trimmed}.difference(self._secrets) + if new: + self._secrets = tuple(sorted((*self._secrets, *new), key=len, reverse=True)) def scrub(self, text: str) -> str: """Return `text` with every registered secret replaced with `[REDACTED]`. diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 8d663e72..c9ac9bca 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -274,6 +274,20 @@ async def test_a_key_is_redacted_whole_when_another_key_is_a_prefix_of_it( assert SENTINEL[-8:] not in app_sinks.everything() +async def test_a_key_with_a_trailing_space_is_redacted_when_echoed_without_it( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + httpserver.expect_request("/allowed", method="POST").respond_with_handler(echo_the_key) + permit = Permit(make_config(httpserver, token=f"{SENTINEL} ", enable=True)) + + with pytest.raises(PermitConnectionError): + await permit.check("user-1", "read", "document") + + [record] = [record for record in app_sinks.sdk_records() if record["level"]["name"] == "ERROR"] + assert record["message"].endswith(f"rejected key: Bearer {REDACTED}") + assert SENTINEL not in app_sinks.everything() + + @pytest.mark.parametrize( ("log", "expected_levels"), [ @@ -406,8 +420,11 @@ def test_an_empty_label_adds_no_prefix(httpserver: HTTPServer, app_sinks: AppSin assert record["message"].startswith(WAIT_FOR_SYNC_WARNING) -def test_an_empty_api_key_redacts_nothing(httpserver: HTTPServer, app_sinks: AppSinks) -> None: - with SyncPermit(make_config(httpserver, token="", enable=True)).wait_for_sync(): +@pytest.mark.parametrize("token", ["", " "]) +def test_an_empty_api_key_redacts_nothing( + httpserver: HTTPServer, app_sinks: AppSinks, token: str +) -> None: + with SyncPermit(make_config(httpserver, token=token, enable=True)).wait_for_sync(): pass [record] = app_sinks.wait_for_sync_warnings() From 9d02291a7e2656da97bc8e9a1c5ef1a24d23496b Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:36:51 +0300 Subject: [PATCH 11/16] Redact the API key from PDP error bodies the SDK raises The SDK replaced a key the PDP echoed back in its own error record, then raised PermitConnectionError with the same body unchanged, so an application that logged or reported the exception wrote the key. Scrub the body where it is read, which covers check, bulk_check and authorized_users, and say in the docs what is and is not replaced. Co-Authored-By: Claude Opus 5.5 --- README.md | 5 ++++- permit/config.py | 8 ++++++-- permit/enforcement/enforcer.py | 8 ++++++++ permit/logger.py | 5 +++-- tests/test_fix_logging.py | 31 ++++++++++++++++++++++++++++++- 5 files changed, 51 insertions(+), 6 deletions(-) diff --git a/README.md b/README.md index 1c63fadb..aa11624d 100644 --- a/README.md +++ b/README.md @@ -60,7 +60,10 @@ permit = Permit(token="", log={"enable": True, "level": "debug"}) - 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. -- No record the SDK logs contains the API key. +- 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 diff --git a/permit/config.py b/permit/config.py index 2ffc9a99..73210b49 100644 --- a/permit/config.py +++ b/permit/config.py @@ -19,8 +19,12 @@ class LoggerConfig(BaseModel): 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. No record the SDK logs - contains the API key: it is replaced with `[REDACTED]`. + 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( diff --git a/permit/enforcement/enforcer.py b/permit/enforcement/enforcer.py index 4b65de20..c9d51027 100644 --- a/permit/enforcement/enforcer.py +++ b/permit/enforcement/enforcer.py @@ -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): diff --git a/permit/logger.py b/permit/logger.py index d0fc4c8a..0c30bfbb 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -27,8 +27,9 @@ def configure_logger(config: PermitConfig) -> None: - `log.log_as_json` is not applied: loguru serializes per sink, with `logger.add(..., serialize=True)`. - The API key in `config.token` is replaced with `[REDACTED]` in every record the SDK - logs, whatever the settings. + 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`. Args: config: The SDK configuration. diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index c9ac9bca..9b7e1fe0 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -249,12 +249,41 @@ async def test_an_api_key_the_pdp_echoes_back_is_redacted( permit = Permit(make_config(httpserver)) logger.enable("permit") - with pytest.raises(PermitConnectionError): + with pytest.raises(PermitConnectionError) as raised: await permit.check("user-1", "read", "document") [record] = [record for record in app_sinks.sdk_records() if record["level"]["name"] == "ERROR"] assert f"rejected key: Bearer {REDACTED}" in record["message"] assert SENTINEL not in app_sinks.everything() + # The application gets the body too, in the exception it may log or report. + assert f"rejected key: Bearer {REDACTED}" in str(raised.value) + assert SENTINEL not in str(raised.value) + + +async def test_errors_raised_for_a_pdp_that_echoes_the_key_do_not_hold_it( + httpserver: HTTPServer, +) -> None: + for path in ("/allowed", "/allowed/bulk", "/authorized_users"): + httpserver.expect_request(path, method="POST").respond_with_handler(echo_the_key) + permit = Permit(make_config(httpserver)) + sync_permit = SyncPermit(make_config(httpserver)) + + raised: list[PermitConnectionError] = [] + for call in ( + lambda: permit.check("user-1", "read", "document"), + lambda: permit.bulk_check(BULK), + lambda: permit.authorized_users("read", "document"), + ): + with pytest.raises(PermitConnectionError) as error: + await call() + raised.append(error.value) + with pytest.raises(PermitConnectionError) as error: + sync_permit.check("user-1", "read", "document") + raised.append(error.value) + + for error_value in raised: + assert f"rejected key: Bearer {REDACTED}" in str(error_value) + assert SENTINEL not in str(error_value) async def test_a_key_is_redacted_whole_when_another_key_is_a_prefix_of_it( From 99ca527bb19582323e0d9d268883670349eec672 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:38:23 +0300 Subject: [PATCH 12/16] Undo only the SDK's own logger.disable when logging is enabled Every client created with log.enable True called logger.enable("permit"). In loguru that also drops every disable the application set for a module of the package, and overrides an application-wide logger.disable(""). Now the SDK calls logger.enable("permit") only to undo a logger.disable("permit") that an earlier client made, which keeps the fix for an enabled client created after a disabled one. Co-Authored-By: Claude Opus 5.5 --- README.md | 4 ++++ permit/config.py | 4 +++- permit/logger.py | 15 ++++++++------- permit/utils/sdk_logger.py | 23 ++++++++++++++++++++--- tests/test_fix_logging.py | 32 +++++++++++++++++++++++++++++++- 5 files changed, 66 insertions(+), 12 deletions(-) diff --git a/README.md b/README.md index aa11624d..8b13e4b5 100644 --- a/README.md +++ b/README.md @@ -51,6 +51,10 @@ permit = Permit(token="", 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`, a level name loguru diff --git a/permit/config.py b/permit/config.py index 73210b49..e3dd2b7b 100644 --- a/permit/config.py +++ b/permit/config.py @@ -30,7 +30,9 @@ class LoggerConfig(BaseModel): enable: bool = Field( default=False, description="Whether the SDK logs. False calls loguru's logger.disable('permit'), so " - "nothing is logged; True calls logger.enable('permit').", + "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", diff --git a/permit/logger.py b/permit/logger.py index 0c30bfbb..45350a32 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -3,9 +3,9 @@ from loguru import logger from permit.config import PermitConfig -from permit.utils.sdk_logger import sdk_logger +from permit.utils.sdk_logger import PACKAGE, sdk_logger -PERMIT_MODULE = "permit" +PERMIT_MODULE = PACKAGE # The names Python's logging module also accepts, and the ones the Node SDK's logger uses. _LEVEL_ALIASES = {"WARN": "WARNING", "FATAL": "CRITICAL"} @@ -20,8 +20,10 @@ def configure_logger(config: PermitConfig) -> None: 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 calls - `logger.enable("permit")`. + - `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, with @@ -39,10 +41,9 @@ def configure_logger(config: PermitConfig) -> None: """ sdk_logger.redact(config.token) if not config.log.enable: - logger.disable(PERMIT_MODULE) + sdk_logger.disable() return - sdk_logger.configure(min_level_no=_level_no(config.log.level), label=config.log.label) - logger.enable(PERMIT_MODULE) + sdk_logger.enable(min_level_no=_level_no(config.log.level), label=config.log.label) def _level_no(level: str) -> int: diff --git a/permit/utils/sdk_logger.py b/permit/utils/sdk_logger.py index 72d70787..07faed11 100644 --- a/permit/utils/sdk_logger.py +++ b/permit/utils/sdk_logger.py @@ -3,6 +3,8 @@ from loguru import logger REDACTED = "[REDACTED]" +# The package whose records loguru's logger.enable() and logger.disable() switch on and off. +PACKAGE = "permit" class SdkLogger: @@ -14,13 +16,15 @@ class SdkLogger: severity, replaces every registered API key with `[REDACTED]` and prefixes the message with the label. - Its settings are process-wide, like loguru's logger. Until `configure` is called, it + Its settings are process-wide, like loguru's logger. Until `enable` is called, it keeps every record and adds no label. """ def __init__(self) -> None: self._min_level_no = 0 self._label = "" + # Whether `disable` called logger.disable("permit") after the last `enable`. + self._disabled_package = False self._secrets_lock = threading.Lock() # Longest first: where one secret contains another, such as a key and a prefix of # it, the whole of the longer one is replaced, not just the shorter part. Replaced, @@ -28,8 +32,18 @@ def __init__(self) -> None: # either the old tuple or the new one. self._secrets: tuple[str, ...] = () - def configure(self, *, min_level_no: int, label: str) -> None: - """Set the minimum severity of the records to keep and the label to prefix them with. + def disable(self) -> None: + """Stop loguru from passing on any record of the package: `logger.disable("permit")`.""" + logger.disable(PACKAGE) + self._disabled_package = True + + def enable(self, *, min_level_no: int, label: str) -> None: + """Keep the records from `min_level_no` up, with `label` before each message. + + If `disable` was called since the last `enable`, this undoes it with + `logger.enable("permit")`. Otherwise it leaves loguru's switches alone: loguru's + enable would also drop every `logger.disable` the application set for a module of + the package, and override an application-wide `logger.disable("")`. Args: min_level_no: The loguru severity number below which records are dropped. @@ -37,6 +51,9 @@ def configure(self, *, min_level_no: int, label: str) -> None: """ self._min_level_no = min_level_no self._label = label + if self._disabled_package: + logger.enable(PACKAGE) + self._disabled_package = False def redact(self, secret: str) -> None: """Replace `secret` with `[REDACTED]` in every record logged from now on. diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 9b7e1fe0..416b046c 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -58,10 +58,15 @@ def _permit_records_enabled() -> bool: @pytest.fixture(autouse=True) def isolated_logging() -> Iterator[None]: - """Start from a fresh SdkLogger, and put both it and loguru's permit switch back after.""" + """Start as a fresh process does, and put the SdkLogger and loguru's switches back after. + + Restoring loguru's switch for "permit" also drops any switch a test set for a module of + the package. + """ was_enabled = _permit_records_enabled() saved = vars(sdk_logger).copy() vars(sdk_logger).update(vars(SdkLogger())) + logger.enable("permit") yield vars(sdk_logger).update(saved) if was_enabled: @@ -535,6 +540,31 @@ def test_the_client_created_last_decides_whether_the_sdk_logs( assert len(app_sinks.wait_for_sync_warnings()) == 1 +def test_an_enabled_client_keeps_a_disable_the_application_set_for_an_sdk_module( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + httpserver.expect_request("/allowed", method="POST").respond_with_json({"allow": True}) + logger.disable("permit.enforcement") + + permit = SyncPermit(make_config(httpserver, enable=True, level="debug")) + assert permit.check("user-1", "read", "document") + + modules = {record["name"] for record in app_sinks.sdk_records()} + assert "permit.permit" in modules + assert [module for module in modules if module.startswith("permit.enforcement")] == [] + + +def test_an_enabled_client_keeps_a_disable_the_application_set_for_the_sdk( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + logger.disable("permit") + + with SyncPermit(make_config(httpserver, enable=True)).wait_for_sync(): + pass + + assert app_sinks.sdk_records() == [] + + def test_the_application_can_still_turn_the_sdk_records_on_itself( httpserver: HTTPServer, app_sinks: AppSinks ) -> None: From abd47f256b31616d7ee033b6de5ea3a7f4466107 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:41:02 +0300 Subject: [PATCH 13/16] Keep the process's log settings when wait_for_sync is used wait_for_sync() created a new client from the config, which ran configure_logger again on every call. That turned SDK logging back on after a client created later with logging disabled, and reset the level and label. It now yields a copy of the client whose PDP and API clients are rebuilt from the new config, through the _connect() hook the blocking client overrides. Co-Authored-By: Claude Opus 5.5 --- README.md | 3 +- permit/permit.py | 18 +++++++--- permit/sync.py | 2 ++ tests/test_fix_logging.py | 73 +++++++++++++++++++++++++++++++++++++++ 4 files changed, 91 insertions(+), 5 deletions(-) diff --git a/README.md b/README.md index 8b13e4b5..faf1d22b 100644 --- a/README.md +++ b/README.md @@ -63,7 +63,8 @@ permit = Permit(token="", log={"enable": True, "level": "debug"}) - `json` is not applied: for JSON output, add a sink with `logger.add(sys.stderr, serialize=True)`. - 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. + 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 diff --git a/permit/permit.py b/permit/permit.py index b86302a5..a636a05c 100644 --- a/permit/permit.py +++ b/permit/permit.py @@ -1,3 +1,4 @@ +import copy from collections.abc import Generator from contextlib import contextmanager from typing import Any, Literal @@ -34,13 +35,17 @@ def __init__(self, config: PermitConfig | None = None, **options: Any) -> None: self._config: PermitConfig = config if config is not None else PermitConfig(**options) configure_logger(self._config) + self._connect() + sdk_logger.debug( + f"Permit SDK initialized: api_url={self._config.api_url}, pdp={self._config.pdp}" + ) + + def _connect(self) -> None: + """Create the clients that send this client's requests, from its config.""" self._enforcer = Enforcer(self._config) self._api = PermitApiClient(self._config) self._elements = ElementsApi(self._config) self._pdp_api = PermitPdpApiClient(self._config) - sdk_logger.debug( - f"Permit SDK initialized: api_url={self._config.api_url}, pdp={self._config.pdp}" - ) @property def config(self) -> PermitConfig: @@ -88,7 +93,12 @@ def wait_for_sync( contextualized_config.facts_sync_timeout = timeout if policy is not None: contextualized_config.facts_sync_timeout_policy = policy - yield self.__class__(contextualized_config) + # A copy of this client that sends its requests with the new config. Creating a new + # client instead would apply its log settings to the whole process again. + waiting: Self = copy.copy(self) + waiting._config = contextualized_config + waiting._connect() + yield waiting @property def api(self) -> PermitApiClient: diff --git a/permit/sync.py b/permit/sync.py index c2e066ad..84bc0d7b 100644 --- a/permit/sync.py +++ b/permit/sync.py @@ -31,6 +31,8 @@ class Permit(AsyncPermit): def __init__(self, config: PermitConfig | None = None, **options: Any) -> None: super().__init__(config, **options) + + def _connect(self) -> None: self._enforcer = SyncEnforcer(self._config) # type: ignore[assignment] self._api = SyncPermitApiClient(self._config) # type: ignore[assignment] self._elements = SyncElementsApi(self._config) # type: ignore[assignment] diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 416b046c..8ffef168 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -7,6 +7,7 @@ """ import json +import re import subprocess import sys import types @@ -565,6 +566,78 @@ def test_an_enabled_client_keeps_a_disable_the_application_set_for_the_sdk( assert app_sinks.sdk_records() == [] +def proxied_config(httpserver: HTTPServer, **log: Any) -> PermitConfig: + """A config that writes facts through the PDP, so `wait_for_sync` derives a client.""" + config = make_config(httpserver, **log) + config.proxy_facts_via_pdp = True + return config + + +def test_wait_for_sync_keeps_logging_off_after_a_disabled_client( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + proxied = SyncPermit(proxied_config(httpserver, enable=True)) + unproxied = SyncPermit(make_config(httpserver, enable=True)) + SyncPermit(make_config(httpserver)) + + with proxied.wait_for_sync(): + pass + with unproxied.wait_for_sync(): + pass + + assert app_sinks.sdk_records() == [] + + +def test_wait_for_sync_keeps_the_level_and_label_of_the_client_created_last( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + proxied = SyncPermit(proxied_config(httpserver, enable=True, level="debug", label="first")) + last = SyncPermit(make_config(httpserver, enable=True, level="warning", label="last")) + records_before = len(app_sinks.sdk_records()) + + with proxied.wait_for_sync(): + pass + with last.wait_for_sync(): + pass + + [record] = app_sinks.sdk_records()[records_before:] + assert record["message"].startswith(f"[last] {WAIT_FOR_SYNC_WARNING}") + + +@pytest.mark.parametrize( + "client_class", [pytest.param(Permit, id="async"), pytest.param(SyncPermit, id="sync")] +) +async def test_wait_for_sync_yields_a_client_that_waits_for_the_facts( + httpserver: HTTPServer, client_class: type[Permit] +) -> None: + serve(httpserver) + httpserver.expect_request(re.compile(r"/facts/tenants/.*"), method="DELETE").respond_with_data( + "", status=204 + ) + permit = client_class(proxied_config(httpserver)) + + with permit.wait_for_sync(timeout=3.0, policy="fail") as waiting: + assert type(waiting) is client_class + assert waiting.config.facts_sync_timeout == 3.0 + deleted = waiting.api.tenants.delete("tenant-1") + if client_class is Permit: + await deleted + deleted = permit.api.tenants.delete("tenant-2") + if client_class is Permit: + await deleted + + [waited, not_waited] = [ + request for request, _ in httpserver.log if request.path.startswith("/facts/") + ] + assert waited.path == "/facts/tenants/tenant-1" + assert (waited.headers.get("X-Wait-Timeout"), waited.headers.get("X-Timeout-Policy")) == ( + "3.0", + "fail", + ) + assert "X-Wait-Timeout" not in not_waited.headers + assert permit.config.facts_sync_timeout is None + + def test_the_application_can_still_turn_the_sdk_records_on_itself( httpserver: HTTPServer, app_sinks: AppSinks ) -> None: From 8f3af5bace37091a15096fb737b2ca198c5c8f6e Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:41:30 +0300 Subject: [PATCH 14/16] Show the JSON log recipe in place of loguru's default sink The documented logger.add(sys.stderr, serialize=True) keeps loguru's default text sink, so every record was printed twice, once as text and once as JSON. Say that the application replaces the default sink with logger.remove() first, in the README, the log_as_json description and the configure_logger docstring. Co-Authored-By: Claude Opus 5.5 --- README.md | 4 +++- permit/config.py | 3 ++- permit/logger.py | 5 +++-- 3 files changed, 8 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index faf1d22b..167b42e6 100644 --- a/README.md +++ b/README.md @@ -60,7 +60,9 @@ permit = Permit(token="", log={"enable": True, "level": "debug"}) requests and the PDP's responses at `"debug"`. With `"enable": True`, a level name loguru does not know raises `ValueError` when the client is created. - `label` (default `"Permit"`) is put in square brackets before every message the SDK logs. -- `json` is not applied: for JSON output, add a sink with `logger.add(sys.stderr, serialize=True)`. +- `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 diff --git a/permit/config.py b/permit/config.py index e3dd2b7b..9332f280 100644 --- a/permit/config.py +++ b/permit/config.py @@ -51,7 +51,8 @@ class LoggerConfig(BaseModel): default=False, alias="json", description="Not applied. The format of the SDK's records is that of the loguru sinks " - "they reach: for JSON, add a sink with logger.add(..., serialize=True).", + "they reach. For JSON, the application replaces loguru's default sink with a " + "serialized one: logger.remove(), then logger.add(sys.stderr, serialize=True).", ) diff --git a/permit/logger.py b/permit/logger.py index 45350a32..04725320 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -26,8 +26,9 @@ def configure_logger(config: PermitConfig) -> None: 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, with - `logger.add(..., serialize=True)`. + - `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 From 5dfe91f99fa83df92ba51859d6feec0c3a187e3f Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 13:41:57 +0300 Subject: [PATCH 15/16] Ban direct use of loguru's logger in the SDK package The API key redaction and the log level and label hold only while every SDK log call goes through permit.utils.sdk_logger. A ruff banned-api rule (TID251) now flags loguru.logger anywhere in permit/ except the wrapper itself and permit/logger.py, which reads loguru's levels. Co-Authored-By: Claude Opus 5.5 --- pyproject.toml | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/pyproject.toml b/pyproject.toml index d177b569..3ef409a0 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -242,6 +242,11 @@ convention = "google" [tool.ruff.lint.flake8-tidy-imports] ban-relative-imports = "all" +[tool.ruff.lint.flake8-tidy-imports.banned-api] +# A record logged straight to loguru would skip the SDK's log level and label, and the +# replacement of the API key with [REDACTED] (PER-16680). +"loguru.logger".msg = "Log through permit.utils.sdk_logger, which redacts the API key." + [tool.ruff.lint.flake8-type-checking] # pydantic evaluates field annotations at runtime, so the imports they use # must never be moved under `if TYPE_CHECKING:`. @@ -271,7 +276,10 @@ runtime-evaluated-base-classes = ["pydantic.BaseModel", "pydantic.v1.BaseModel"] "T201", # progress output for long e2e runs; pytest captures it "BLE001", # e2e tests turn any unexpected exception into a readable pytest.fail "S603", # subprocesses run the interpreter under test with the test's own arguments + "TID251", # tests add loguru sinks and log the way an application does ] +# The SDK's loguru wrapper, and the module that reads loguru's levels for log.level. +"permit/{logger,utils/sdk_logger}.py" = ["TID251"] # These are standalone CLI programs, not library code: writing the rendered # report to stdout IS their interface, so the "no print" rule does not apply. "{.github/scripts,scripts,skills/permit-python-3-migration/scripts}/*.py" = [ From 3e3688782791eb963ecabb8261637a60d58fcc92 Mon Sep 17 00:00:00 2001 From: Zeev Manilovich Date: Thu, 1 Oct 2026 14:26:35 +0300 Subject: [PATCH 16/16] Warn and log at INFO for an unknown log level instead of raising An unknown log.level was ignored before this branch, so raising ValueError at client creation would break an app on upgrade. The SDK now logs a warning that names the value and uses INFO. The traceback test forces a failure inside configure_logger instead, and still checks that the API key never shows. Co-Authored-By: Claude Opus 5.5 --- README.md | 4 ++-- permit/config.py | 4 ++-- permit/logger.py | 26 +++++++++++++++----------- tests/test_fix_logging.py | 31 +++++++++++++++++++++++++------ 4 files changed, 44 insertions(+), 21 deletions(-) diff --git a/README.md b/README.md index 167b42e6..01e3ed49 100644 --- a/README.md +++ b/README.md @@ -57,8 +57,8 @@ permit = Permit(token="", log={"enable": True, "level": "debug"}) 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`, a level name loguru - does not know raises `ValueError` when the client is created. + 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)`. diff --git a/permit/config.py b/permit/config.py index 9332f280..490c6576 100644 --- a/permit/config.py +++ b/permit/config.py @@ -39,8 +39,8 @@ class LoggerConfig(BaseModel): 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; a name loguru does not know raises ValueError when the " - "client is created.", + "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", diff --git a/permit/logger.py b/permit/logger.py index 04725320..48f35113 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -34,29 +34,33 @@ def configure_logger(config: PermitConfig) -> None: 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. - - Raises: - ValueError: If `log.enable` is True and `log.level` is not the name of a loguru level. """ sdk_logger.redact(config.token) if not config.log.enable: sdk_logger.disable() return - sdk_logger.enable(min_level_no=_level_no(config.log.level), label=config.log.label) + 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: +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 - msg = ( - f"Invalid log level {level!r} in the Permit SDK config (log.level): use trace, " - "debug, info, success, warning, error or critical, or a level added with " - "loguru's logger.level()." - ) - raise ValueError(msg) + return None diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py index 8ffef168..5422f424 100644 --- a/tests/test_fix_logging.py +++ b/tests/test_fix_logging.py @@ -349,23 +349,42 @@ async def test_level_drops_the_sdk_records_below_it( assert "an application record" in [record["message"] for record in app_sinks.records()] -def test_an_unknown_level_fails_when_the_client_is_created(httpserver: HTTPServer) -> None: - with pytest.raises(ValueError, match=r"Invalid log level 'verbose'"): - SyncPermit(make_config(httpserver, enable=True, level="verbose")) +async def test_an_unknown_level_warns_and_logs_at_info( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + serve(httpserver) + + await use_async_client(Permit(make_config(httpserver, enable=True, level="verbose"))) + + warnings = [ + record + for record in app_sinks.sdk_records() + if record["level"]["name"] == "WARNING" + and "Unknown log level 'verbose'" in record["message"] + ] + assert len(warnings) == 1 + assert "logs at INFO" in warnings[0]["message"] + # The same records as with level "info": no DEBUG ones. + assert app_sinks.sdk_levels() == {"WARNING", "ERROR"} def test_the_traceback_of_a_failed_client_creation_hides_the_api_key( - httpserver: HTTPServer, + httpserver: HTTPServer, monkeypatch: pytest.MonkeyPatch ) -> None: + def fail(**_: object) -> None: + msg = "the SDK could not configure its logger" + raise RuntimeError(msg) + + monkeypatch.setattr("permit.logger.sdk_logger.enable", fail) lines: list[str] = [] # diagnose=True, loguru's default, prints the value of each name on every line of the # traceback, and the SDK's frames pass the config around. sink_id = logger.add(lines.append, diagnose=True, backtrace=True) - config = make_config(httpserver, enable=True, level="verbose") + config = make_config(httpserver, enable=True) try: try: SyncPermit(config) - except ValueError: + except RuntimeError: logger.exception("the application could not start") finally: logger.remove(sink_id)