diff --git a/README.md b/README.md index e249ce14..72ae6bb1 100644 --- a/README.md +++ b/README.md @@ -40,6 +40,71 @@ 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. +- `"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, loguru's `logger.enable("permit")` also undoes your + application's own `logger.disable("permit")`, every `logger.disable()` your application + made for a `permit.*` module, before or since, and, for the SDK's records, an + application-wide `logger.disable("")`. Make those calls after creating the clients if + they must hold. +- `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, as given and in lower case, + with `[REDACTED]` in: + - the messages it logs; + - the messages of the exceptions it raises, and the error bodies in them + (`PermitApiError.details`); + - the aiohttp response or error those exceptions carry (`original_error`, `response`, + the cause), and the exceptions chained under that error (as a cause or a context, or + as a member of an exception group) that aiohttp and the libraries it uses raised + during the request: the request headers they keep, the request headers of the + redirect responses in their `history`, and each error's arguments and attributes + that are strings or bytes (such as its message), the response headers it keeps, and + the URL of an invalid-URL error (`InvalidURL.url`, which then becomes a string). + + The SDK never changes an exception it did not raise during the request, such as one + your application was handling when it called the SDK, which aiohttp keeps in its + error's chain. If the key cannot be removed from the aiohttp error or an exception + under it, or is still in one under it that the SDK leaves as it is (other than the one + your application was handling), a `PermitConnectionError` carries a plain + `aiohttp.ClientError` that says so in its place, as `original_error` and as the cause, + and a `PermitApiError` for an error body that isn't JSON has no cause. + + It does not replace the key elsewhere: not in values that are neither text nor a URL, + such as a parsed HTTP message; not in request URLs (`PermitApiError.request_url`, the + `url` and `real_url` of a response or its `request_info`, the `url=` part of an aiohttp + error's text); not in the headers or raw body of a response itself + (`PermitApiError.response.headers`, a redirect response's `Location`, + `await PermitApiError.response.text()`); and not in the values a traceback shows for + each frame (loguru's `diagnose=True`, error trackers that record local variables), where + the key is in the client's options and its request headers. A key shorter than 12 + characters is not replaced. The client's start-up line shows `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 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/config.py b/permit/config.py index 7a42f941..bb48dbd2 100644 --- a/permit/config.py +++ b/permit/config.py @@ -13,22 +13,49 @@ 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, in the messages and error bodies of the + exceptions it raises, and in the aiohttp objects those exceptions carry; the README + lists what it does not cover. 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. When it does " + "undo it, loguru also drops every logger.disable() set for 'permit' or one of its " + "modules, and overrides an application-wide logger.disable('') for the SDK's records.", ) 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 +81,12 @@ 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. Tracebacks that print + # frame values, such as loguru's with diagnose=True, still show it in other values: the + # options a client is created with, and the headers of its HTTP clients. token: str = Field( ..., + repr=False, description="The token (API Key) used for authorization against the PDP " "and the Permit REST API.", ) diff --git a/permit/enforcement/enforcer.py b/permit/enforcement/enforcer.py index 119a5d4e..8eeab9fa 100644 --- a/permit/enforcement/enforcer.py +++ b/permit/enforcement/enforcer.py @@ -1,11 +1,11 @@ import json +import sys from http import HTTPStatus from pprint import pformat from typing import TYPE_CHECKING, Any, Union import aiohttp from aiohttp import ClientTimeout -from loguru import logger from typing_extensions import NotRequired, TypedDict from permit.config import PermitConfig @@ -14,6 +14,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,13 +54,23 @@ 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): pass try: - text = (await response.text()).strip() + # errors="replace": a body that isn't valid in its charset must not escape as a + # UnicodeDecodeError, which isn't a PermitError and keeps the raw, unscrubbed bytes. + text = (await response.text(errors="replace")).strip() except aiohttp.ClientError: return "" return text or "" @@ -92,6 +103,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: @@ -156,6 +169,7 @@ async def authorized_users( "context": query_context, } + handled = sys.exc_info()[1] # the application's, if any: left as it is async with aiohttp.ClientSession(headers=self._headers, **self._timeout_config) as session: check_url = f"{self._base_url}/authorized_users" try: @@ -172,14 +186,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 +203,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,29 +212,31 @@ async def authorized_users( raise PermitConnectionError(msg) content: dict[str, Any] = await response.json() - logger.debug( - f"permit.authorized_users() response:" - f"\ninput: {pformat(request_body, indent=2)}" - f"\nresponse status: {response.status}" - f"\nresponse data: {pformat(content, indent=2)}" + sdk_logger.debug( + lambda: ( + f"permit.authorized_users() response:" + f"\ninput: {pformat(request_body, indent=2)}" + f"\nresponse status: {response.status}" + f"\nresponse data: {pformat(content, indent=2)}" + ) ) 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( - msg, - error=err, - ) from err + error = PermitConnectionError(msg, error=err, handled=handled) + # Raised after the `except` block, so `err` isn't its context when it isn't + # attached. + raise error from error.original_error async def bulk_check( self, @@ -291,6 +307,7 @@ async def bulk_check( } ) + handled = sys.exc_info()[1] # the application's, if any: left as it is async with aiohttp.ClientSession(headers=self._headers, **self._timeout_config) as session: check_url = f"{self._base_url}/allowed/bulk" try: @@ -314,14 +331,16 @@ 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( - f"permit.check() response:\n" - f"input: {pformat(request_body, indent=2)}\n" - f"response status: {response.status}\n" - f"response data: {pformat(content, indent=2)}" + sdk_logger.debug( + lambda: ( + f"permit.check() response:\n" + f"input: {pformat(request_body, indent=2)}\n" + f"response status: {response.status}\n" + f"response data: {pformat(content, indent=2)}" + ) ) data = content.get("allow", content.get("result", {}).get("allow", [])) decisions: list[bool] = [bool(item.get("allow", False)) for item in data] @@ -339,9 +358,13 @@ async def bulk_check( ), err, ) - logger.error(msg) - raise PermitConnectionError(msg, error=err) from err - return decisions + sdk_logger.error(msg) + error = PermitConnectionError(msg, error=err, handled=handled) + else: + return decisions + # Raised after the `except` block, so `err` isn't its context when it isn't + # attached. + raise error from error.original_error async def check( self, @@ -394,6 +417,7 @@ async def check( "resource": normalized_resource.dict(exclude_unset=True), "context": query_context, } + handled = sys.exc_info()[1] # the application's, if any: left as it is async with aiohttp.ClientSession(headers=self._headers, **self._timeout_config) as session: check_url = f"{self._base_url}/allowed" try: @@ -410,13 +434,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 +451,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,16 +460,18 @@ async def check( raise PermitConnectionError(msg) content: dict[str, Any] = await response.json() - logger.debug( - f"permit.check() response:\n" - f"body: {pformat(body, indent=2)}\n" - f"response status: {response.status}\n" - f"response data: {pformat(content, indent=2)}" + sdk_logger.debug( + lambda: ( + f"permit.check() response:\n" + f"body: {pformat(body, indent=2)}\n" + f"response status: {response.status}\n" + f"response data: {pformat(content, indent=2)}" + ) ) 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,13 +480,13 @@ 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( - msg, - error=err, - ) from err + error = PermitConnectionError(msg, error=err, handled=handled) + # Raised after the `except` block, so `err` isn't its context when it isn't + # attached. + raise error from error.original_error async def get_user_permissions( self, @@ -490,6 +516,7 @@ async def get_user_permissions( "resource_types": resource_types, } + handled = sys.exc_info()[1] # the application's, if any: left as it is async with aiohttp.ClientSession(headers=self._headers, **self._timeout_config) as session: url = f"{self._base_url}/user-permissions" try: @@ -514,26 +541,28 @@ async def get_user_permissions( else content ) - logger.debug( - f"permit.get_user_permissions() response:\n" - f"input: {pformat(input_data, indent=2)}\n" - f"response data: {pformat(permissions, indent=2)}" + sdk_logger.debug( + lambda: ( + 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( - msg, - error=err, - ) from err + error = PermitConnectionError(msg, error=err, handled=handled) + # Raised after the `except` block, so `err` isn't its context when it isn't + # attached. + raise error from error.original_error async def filter_objects( self, user: User, action: Action, context: Context, resources: list[dict[str, Any]] diff --git a/permit/exceptions.py b/permit/exceptions.py index 5a71176e..49359567 100644 --- a/permit/exceptions.py +++ b/permit/exceptions.py @@ -1,14 +1,17 @@ import functools +import json as json_module +import sys import warnings -from collections.abc import Awaitable, Callable, Coroutine +from collections.abc import Awaitable, Callable, Coroutine, Mapping from http import HTTPStatus -from typing import TYPE_CHECKING, Any, TypeVar +from typing import TYPE_CHECKING, Any, TypeVar, cast import aiohttp -from loguru import logger +from multidict import CIMultiDict, CIMultiDictProxy 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. @@ -52,8 +55,27 @@ class PermitConnectionError(PermitException): # type: ignore[deprecated] # kept with a changelog entry, not in a dependency-security patch. """ - def __init__(self, message: str, *, error: aiohttp.ClientError | None = None) -> None: - super().__init__(message) + def __init__( + self, + message: object, + *, + error: aiohttp.ClientError | None = None, + handled: BaseException | None = None, + ) -> None: + # Every raise site builds its message from response bodies and aiohttp error + # text, so the key is replaced here, once, rather than at each of them. The + # class is public, and a message that isn't a string is kept as it is. + # `handled` is the exception the application was handling when it called the + # SDK (see `scrub_request_info`). + super().__init__(sdk_logger.scrub(message) if isinstance(message, str) else message) + if error is not None and not scrub_request_info(error, handled=handled): + # Fail closed: an error the key could not be removed from is not attached. + # The SDK raises this exception `from original_error`, so it is not the + # cause either. + error = aiohttp.ClientError( + f"{type(error).__name__}, not attached: the API key could not be " + "removed from it" + ) self.original_error = error @@ -85,6 +107,9 @@ def __init__( body: dict[str, Any] | None = None, ) -> None: super().__init__() + # The result isn't needed: on a `ClientResponse` the scrub writes only + # `_request_info` and its cache, a plain attribute and a dict, so it can't fail. + scrub_request_info(response) self._response = response self._body = body @@ -229,6 +254,307 @@ class PermitNotFoundError(PermitApiDetailedError): """Object not found response from the Permit API.""" +_JsonT = TypeVar("_JsonT") + + +def _scrubbed(value: _JsonT) -> _JsonT: + """Return `value`, a decoded JSON body, with every registered API key replaced. + + Strings are scrubbed wherever they are, object keys included. + """ + if isinstance(value, str): + return cast("_JsonT", sdk_logger.scrub(value)) + if isinstance(value, list): + return cast("_JsonT", [_scrubbed(item) for item in value]) + if isinstance(value, dict): + return cast( + "_JsonT", + {_scrubbed(key): _scrubbed(item) for key, item in value.items()}, + ) + return value + + +def _scrubbed_headers(headers: Mapping[str, str]) -> CIMultiDictProxy[str]: + return CIMultiDictProxy( + CIMultiDict((name, sdk_logger.scrub(value)) for name, value in headers.items()) + ) + + +# The packages whose code an SDK request runs through: aiohttp, the libraries it raises +# errors from, asyncio, and the SDK itself. +_REQUEST_PACKAGES = frozenset( + { + "aiohappyeyeballs", + "aiohttp", + "asyncio", + "concurrent", + "multidict", + "permit", + "propcache", + "selectors", + "socket", + "ssl", + "yarl", + } +) + + +def _raised_in_the_request(error: BaseException) -> bool: + """Whether `error` was raised and caught within the SDK's request. + + That is, whether every frame of its traceback is in one of `_REQUEST_PACKAGES`. An + exception the application raised or caught has a frame of the application's, so the + SDK doesn't change it. So does an error raised in a library missing from the list, + which `_scrub_chain` then checks for a key instead. + """ + frame = error.__traceback__ + if frame is None: + return False + while frame is not None: + module = frame.tb_frame.f_globals.get("__name__") + if not isinstance(module, str) or module.partition(".")[0] not in _REQUEST_PACKAGES: + return False + frame = frame.tb_next + return True + + +def _chained(error: BaseException) -> list[BaseException | None]: + """The exceptions right under `error`: its cause and context, and a group's members. + + A traceback shows every member of an exception group, and what is chained under each. + The members are read from `exceptions`, which the exception groups of the backport for + Python 3.10 have too. + """ + chained: list[BaseException | None] = [error.__cause__, error.__context__] + members = getattr(error, "exceptions", None) + if isinstance(members, tuple): + chained += [member for member in members if isinstance(member, BaseException)] + return chained + + +def _chain( + error: BaseException, handled: BaseException | None +) -> tuple[list[BaseException], list[BaseException]]: + """The exceptions reachable from `error`, one `_chained` step at a time. + + Returns them in two lists: those to scrub, which are `error`, the one the SDK caught, + and those under it raised in the request; and the others under it, which are left as + they are and which the walk doesn't go past. `handled` and what is chained under it + are in neither: they are the application's. + """ + scrub: list[BaseException] = [error] + left: list[BaseException] = [] + seen: set[int] = {id(error)} + if handled is not None: + seen.add(id(handled)) + pending = _chained(error) + while pending: + current = pending.pop() + if current is None or id(current) in seen: + continue + seen.add(id(current)) + if _raised_in_the_request(current): + scrub.append(current) + pending += _chained(current) + else: + left.append(current) + return scrub, left + + +# Text a builtin exception keeps in fields of its own, outside `__dict__` and `args`: a +# `UnicodeError`'s `object`, an `OSError`'s file names and `strerror`, a `SyntaxError`'s +# `text`. +_BUILTIN_TEXT_FIELDS = ("object", "filename", "filename2", "strerror", "text") + + +def _holds_key(error: BaseException) -> bool: + """Whether the text `error` keeps or shows holds a registered key.""" + shown = [str(error), repr(error.args), repr(getattr(error, "__dict__", {}))] + shown += [repr(getattr(error, name)) for name in _BUILTIN_TEXT_FIELDS if hasattr(error, name)] + return any(sdk_logger.scrub(text) != text for text in shown) + + +def _below(errors: list[BaseException], handled: BaseException | None) -> list[BaseException]: + """`errors` and everything chained under them, `handled` and what is under it apart.""" + found: list[BaseException] = [] + seen: set[int] = set() if handled is None else {id(handled)} + pending: list[BaseException | None] = list(errors) + while pending: + current = pending.pop() + if current is None or id(current) in seen: + continue + seen.add(id(current)) + found.append(current) + pending += _chained(current) + return found + + +def _scrubbed_value(value: object) -> object: + """`value` with every registered key replaced, if it is text that can hold one. + + That is a string, bytes, or a yarl URL, which comes back as a string when it holds a + key. Any other value, such as a parsed HTTP message, comes back as it is, and so does + a value without a key: the very same object. + """ + scrubbed: object = value + if isinstance(value, str): + scrubbed = sdk_logger.scrub(value) + elif isinstance(value, bytes): + scrubbed = sdk_logger.scrub_bytes(value) + elif isinstance(value, bytearray): + scrubbed = bytearray(sdk_logger.scrub_bytes(bytes(value))) + elif type(value).__module__.partition(".")[0] == "yarl": + text = str(value) + scrubbed = sdk_logger.scrub(text) + if scrubbed == text: + return value + return value if scrubbed == value else scrubbed + + +def _replace(holder: object, name: str, value: object) -> bool: + """Set `holder.name` to `value`; False, never an exception, if it can't be set.""" + try: + setattr(holder, name, value) + except Exception: # noqa: BLE001 - any failure is reported, never raised + return False + return True + + +def _scrub_error_text(error: BaseException) -> bool: + """Replace the key in the text `error` keeps; False if some of it can't be replaced. + + The text is its arguments and its attributes: a `message`, a `line`, an + `InvalidURL`'s `_url`, and the like. Only values that hold a key are written. + """ + scrubbed = True + for name, value in list(getattr(error, "__dict__", {}).items()): + if name == "headers" and isinstance(value, Mapping): + items = [(key, item, _scrubbed_value(item)) for key, item in value.items()] + if any(new is not item for _, item, new in items): + headers = CIMultiDictProxy(CIMultiDict((key, new) for key, _, new in items)) + scrubbed &= _replace(error, name, headers) + continue + new_value = _scrubbed_value(value) + if new_value is not value: + scrubbed &= _replace(error, name, new_value) + args = tuple(_scrubbed_value(arg) for arg in error.args) + if any(new is not arg for new, arg in zip(args, error.args, strict=True)): + scrubbed &= _replace(error, "args", args) + return scrubbed + + +def scrub_request_info(holder: object, *, handled: BaseException | None = None) -> bool: + """Replace every client's API key in the request headers and error text `holder` keeps. + + aiohttp keeps the request's headers, `Authorization` included, on a + `ClientResponse` and a `ClientResponseError` (`request_info`, which the error also + keeps as `args[0]`), and on the redirect responses in their `history`; their `repr` + prints them. An aiohttp error's text may also hold text a server sent: its string and + bytes arguments and attributes (a `ClientResponseError`'s `message`, an `InvalidURL`'s + URL), the response `headers` it keeps, and the same in the HTTP parser and URL errors + chained under it. The SDK puts such objects in the exceptions it raises + (`original_error`, `response`, the exception's cause), so it scrubs them first. + + Only values that hold a key are changed, in the error itself and in what was raised + within the request under it (see `_raised_in_the_request`). `handled`, the exception + the application was handling when it called the SDK, which aiohttp's errors keep as + their `__context__`, is left as it is, and so is everything chained under it. So are + a `ClientResponse`'s own URL, headers and body, and values that aren't text, such as a + parsed HTTP message. + + Args: + holder: An aiohttp response or client error. + handled: The exception the application was handling when it called the SDK. + + Returns: + False if the key may still be in what `holder` keeps: a value that holds it could + not be replaced, or an exception left as it is holds it. It never raises. + """ + try: + if isinstance(holder, BaseException): + return _scrub_chain(holder, handled) + return _scrub_holder(holder) + except Exception: # noqa: BLE001 - a scrub that fails is reported, never raised + return False + + +def _scrub_chain(error: BaseException, handled: BaseException | None) -> bool: + scrubbed = True + to_scrub, left = _chain(error, handled) + # Every one is scrubbed, even after one that could not be. + for chained in to_scrub: + scrubbed &= _scrub_holder(chained) + # The key can still be where no write reaches: in text kept outside `__dict__` (a + # `UnicodeError`'s `object`), or in an exception left as it is, or under one. + return scrubbed and not any(_holds_key(shown) for shown in [*to_scrub, *_below(left, handled)]) + + +def _scrub_holder(holder: object) -> bool: + scrubbed = True + for redirect in getattr(holder, "history", None) or (): + if redirect is not holder: + scrubbed &= scrub_request_info(redirect) + if isinstance(holder, BaseException): + scrubbed &= _scrub_error_text(holder) + info = getattr(holder, "request_info", None) + if not isinstance(info, aiohttp.RequestInfo): + return scrubbed + headers = _scrubbed_headers(info.headers) + if headers == info.headers: + return scrubbed + replacement = aiohttp.RequestInfo(info.url, info.method, headers, info.real_url) + if isinstance(holder, aiohttp.ClientResponse): + # `request_info` is a read-only property over `_request_info`, cached once read + # (aiohttp's `reify`): replace both. tests/test_fix_logging.py checks the result. + scrubbed &= _replace(holder, "_request_info", replacement) + cache = getattr(holder, "_cache", None) + if isinstance(cache, dict) and "request_info" in cache: + cache["request_info"] = replacement + return scrubbed + scrubbed &= _replace(holder, "request_info", replacement) + if isinstance(holder, BaseException): + args = tuple(replacement if arg is info else arg for arg in holder.args) + scrubbed &= _replace(holder, "args", args) + return scrubbed + + +def _scrubbed_loads(text: str) -> Any: # noqa: ANN401 - any JSON value + return json_module.loads(sdk_logger.scrub(text)) + + +async def _scrubbed_text(response: aiohttp.ClientResponse) -> str: + """The body of `response` as text, every registered API key replaced.""" + return sdk_logger.scrub(await response.text(errors="replace")) + + +async def _error_json(response: aiohttp.ClientResponse) -> Any: # noqa: ANN401 - any JSON value + """The decoded JSON body of an error response, every registered API key replaced. + + Raises: + PermitApiError: When the body is not JSON, whatever its Content-Type says. + """ + handled = sys.exc_info()[1] + cause: aiohttp.ContentTypeError | None = None + try: + # The body is scrubbed before it is parsed too, so a decode error's `doc` never + # holds the key. + return _scrubbed(await response.json(loads=_scrubbed_loads)) + except aiohttp.ContentTypeError as e: + # Not chained to an error the key could not be removed from. + if scrub_request_info(e, handled=handled): + cause = e + except ValueError: + # Labelled JSON but not JSON, such as a proxy's error page or a truncated body. + # A UnicodeDecodeError keeps the raw bytes, so the decode error isn't chained. + pass + # Raised after the `except` blocks, so the error caught there isn't the new + # exception's context. + error = PermitApiError(response, {"details": await _scrubbed_text(response)}) + if cause is None: + raise error + raise error from cause + + async def handle_api_error(response: aiohttp.ClientResponse) -> None: """Raise the matching SDK exception if `response` has a non-2xx status. @@ -245,11 +571,7 @@ async def handle_api_error(response: aiohttp.ClientResponse) -> None: if HTTPStatus.OK <= response.status < HTTPStatus.MULTIPLE_CHOICES: return - try: - json = await response.json() - except aiohttp.ContentTypeError as e: - text = await response.text() - raise PermitApiError(response, {"details": text}) from e + json = await _error_json(response) if response.status == HTTPStatus.UNPROCESSABLE_ENTITY: try: @@ -285,11 +607,15 @@ def handle_client_error( @functools.wraps(func) async def wrapped(*args: P.args, **kwargs: P.kwargs) -> R: + handled = sys.exc_info()[1] 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 + error = PermitConnectionError(msg, error=err, handled=handled) + # Raised after the `except` block, so `err` isn't its context when it isn't + # attached. + raise error from error.original_error return wrapped diff --git a/permit/logger.py b/permit/logger.py index d1677f87..31bf1c0f 100644 --- a/permit/logger.py +++ b/permit/logger.py @@ -1,15 +1,96 @@ +import contextlib +import contextvars +import threading + from loguru import logger from permit.config import PermitConfig +from permit.utils.sdk_logger import PACKAGE, sdk_logger + +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"} -PERMIT_MODULE = "permit" +# Set while a client derives another from itself (`Permit.wait_for_sync`): the derived +# client keeps the process's log settings instead of applying its own again. +keep_log_settings: contextvars.ContextVar[bool] = contextvars.ContextVar( + "permit_keep_log_settings", default=False +) + +# The unknown level names already warned about, so a process that creates a client per +# request warns once per name. +_warned_levels: set[str] = set() +_warned_levels_lock = threading.Lock() def configure_logger(config: PermitConfig) -> None: - """Silence the SDK's loguru output unless the config enables logging. + """Apply the `log` settings of `config` to the SDK's log records. + + The settings are process-wide, as loguru's logger is: the client created last decides + whether the SDK logs, and the last one created with `log.enable` True decides the level + and the label, for every client. The SDK adds no sink and leaves the application's sinks + and levels alone, so its records are written wherever loguru writes the application's, + in the format of those sinks. + + - `log.enable` False calls `logger.disable("permit")`, so nothing is logged. True + undoes that call with `logger.enable("permit")` if an earlier client made it, and + otherwise leaves loguru's switches alone, so a `logger.disable` the application made + for the package or one of its modules still applies. Undoing it also drops every + `logger.disable` set for the package or one of its modules, before or since, and + overrides an application-wide `logger.disable("")` for the SDK's records. + - `log.level` drops the SDK's records below that severity before they reach any sink. + - `log.label` is put in brackets before each message. + - `log.log_as_json` is not applied: loguru serializes per sink. For JSON output, the + application replaces loguru's default sink with a serialized one: `logger.remove()`, + then `logger.add(sys.stderr, serialize=True)`. + + Whatever the settings, the API key in `config.token` is replaced with `[REDACTED]` in + every message the SDK logs, in the messages and error bodies of the exceptions it + raises, and in the aiohttp objects those exceptions carry. + + `log.level` is a level name, in any case, or a loguru severity number. An unknown one + does not fail client creation: the SDK logs a warning that names the value, once per + process, and uses INFO. + + While `keep_log_settings` is set (`Permit.wait_for_sync` deriving a client), only the + key is registered for redaction: the process's log settings stay as they are. Args: - config: The SDK configuration; only `config.log.enable` is read. + config: The SDK configuration. """ + sdk_logger.redact(config.token) + if keep_log_settings.get(): + return if not config.log.enable: - logger.disable(PERMIT_MODULE) + sdk_logger.disable() + return + level_no = _level_no(config.log.level) + if level_no is None: + sdk_logger.enable(min_level_no=logger.level("INFO").no, label=config.log.label) + with _warned_levels_lock: + if config.log.level in _warned_levels: + return + _warned_levels.add(config.log.level) + sdk_logger.warning( + f"Unknown log level {config.log.level!r} in the Permit SDK config (log.level), " + "so the SDK logs at INFO. Use trace, debug, info, success, warning, error or " + "critical, or a level added with loguru's logger.level()." + ) + return + sdk_logger.enable(min_level_no=level_no, label=config.log.label) + + +def _level_no(level: str) -> int | None: + level = level.strip() + # A severity number, as loguru accepts it (pydantic turns `10` into "10"). isdecimal, + # not isdigit: it is true for exactly the digits int() reads, and "²" is not one. + if level.isdecimal(): + return int(level) + upper = level.upper() + # loguru's level names are case-sensitive: try the name as given first, so a level the + # application added in lower case is found, then the upper-case name of a built-in one. + for name in (level, _LEVEL_ALIASES.get(upper, upper)): + with contextlib.suppress(ValueError): + return logger.level(name).no + return None diff --git a/permit/permit.py b/permit/permit.py index 51d6f51f..5524065f 100644 --- a/permit/permit.py +++ b/permit/permit.py @@ -1,9 +1,7 @@ -import json from collections.abc import Generator 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 @@ -17,9 +15,10 @@ User, ) from permit.enforcement.interfaces import AuthorizedUsersResult -from permit.logger import configure_logger +from permit.logger import configure_logger, keep_log_settings from permit.pdp_api.pdp_api_client import PermitPdpApiClient from permit.utils.context import Context +from permit.utils.sdk_logger import sdk_logger, without_userinfo class Permit: @@ -39,9 +38,9 @@ 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( - "Permit SDK initialized with config:\n${}", - json.dumps(self._config.dict(exclude={"api_context"})), + sdk_logger.debug( + f"Permit SDK initialized: api_url={without_userinfo(self._config.api_url)}, " + f"pdp={without_userinfo(self._config.pdp)}" ) @property @@ -81,7 +80,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 @@ -90,7 +89,14 @@ 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 client of this class, so a subclass's own setup runs, that keeps the process's + # log settings: applying this client's again would undo a client created since. + token = keep_log_settings.set(True) + try: + waiting = self.__class__(contextualized_config) + finally: + keep_log_settings.reset(token) + yield waiting @property def api(self) -> PermitApiClient: diff --git a/permit/utils/sdk_logger.py b/permit/utils/sdk_logger.py new file mode 100644 index 00000000..c972c755 --- /dev/null +++ b/permit/utils/sdk_logger.py @@ -0,0 +1,165 @@ +import threading +from collections.abc import Callable +from typing import TypeAlias +from urllib.parse import urlsplit, urlunsplit + +from loguru import logger + +REDACTED = "[REDACTED]" +# A secret shorter than this is not redacted: replacing a short value such as "token" in +# every message would mangle the SDK's own text. Permit API keys are far longer. +MIN_SECRET_LENGTH = 12 +# The package whose records loguru's logger.enable() and logger.disable() switch on and off. +PACKAGE = "permit" + +# A message, or a function that builds it, for a message costly to build: it is called +# only for a record that some sink will receive. +Message: TypeAlias = str | Callable[[], str] + + +class SdkLogger: + """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 drops records below the minimum + severity. For a record loguru passes on, the message is then built, prefixed with the + label and has every registered API key replaced with `[REDACTED]`; for one it drops, + while the package is disabled or below every sink's level, none of that is done. + + 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 + # Held while the loguru switch and `_disabled_package` change together, so two + # clients created at once in different threads leave them consistent. + self._switch_lock = threading.Lock() + 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, + # 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 disable(self) -> None: + """Stop loguru from passing on any record of the package: `logger.disable("permit")`.""" + with self._switch_lock: + 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")`, which also drops every `logger.disable` set for a module + of the package and overrides an application-wide `logger.disable("")` for its + records. Otherwise it leaves loguru's switches alone, so those still apply. + + 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. + """ + with self._switch_lock: + 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. + + 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. So is each in lower case: aiohttp lower-cases + some of the server text it puts in its error messages, such as a Content-Type. + + Args: + secret: A credential, such as an API key. A secret shorter than + `MIN_SECRET_LENGTH` without its surrounding whitespace is ignored. + """ + trimmed = secret.strip() + if len(trimmed) < MIN_SECRET_LENGTH: + return + with self._secrets_lock: + new = {secret, trimmed, secret.lower(), trimmed.lower()}.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]`. + + 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 scrub_bytes(self, data: bytes) -> bytes: + """Return `data` with every registered secret, UTF-8 encoded, replaced. + + Args: + data: Bytes a server sent, such as an HTTP line an aiohttp error keeps. + + Returns: + The bytes without any registered secret. + """ + for secret in self._secrets: + data = data.replace(secret.encode(), REDACTED.encode()) + return data + + def debug(self, message: Message) -> None: + """Log `message` with severity DEBUG.""" + self._log("DEBUG", message) + + def warning(self, message: Message) -> None: + """Log `message` with severity WARNING.""" + self._log("WARNING", message) + + def error(self, message: Message) -> None: + """Log `message` with severity ERROR.""" + self._log("ERROR", message) + + def _log(self, level: str, message: Message) -> None: + if logger.level(level).no < self._min_level_no: + return + label = self._label + # depth=2 skips this method and the one that called it, so loguru attributes the + # record to the SDK module that logged it. lazy=True: loguru calls the function + # only once its enabled and level checks pass, so a record it drops is never built + # or scrubbed. The message is the argument of "{}", so braces in it are kept. + logger.opt(depth=2, lazy=True).log(level, "{}", lambda: self._render(message, label)) + + def _render(self, message: Message, label: str) -> str: + text = message() if callable(message) else message + if label: + text = f"[{label}] {text}" + # After the label goes on, so a key in the label is replaced too. + return self.scrub(text) + + +def without_userinfo(url: str) -> str: + """`url` without a user name or password, which a proxy URL may carry. + + For a log line or an exception message: it never raises, and a URL it can't parse + comes back as ``. + """ + try: + parts = urlsplit(url) + except ValueError: + return "" + if "@" not in parts.netloc: + return url + return urlunsplit(parts._replace(netloc=parts.netloc.rpartition("@")[2])) + + +sdk_logger = SdkLogger() diff --git a/pyproject.toml b/pyproject.toml index d177b569..8c508b20 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -30,6 +30,12 @@ classifiers = [ # .github/scripts/audit-deps.sh scans them with --resolution lowest-direct. dependencies = [ "aiohttp>=3.14.3,<4", + # Imported directly (permit/exceptions.py). aiohttp requires it too, in this range, + # so this adds no constraint. The floor is aiohttp's: permit uses only CIMultiDict and + # CIMultiDictProxy, and its tests pass on 4.5.0. So the floor lanes + # (--resolution lowest-direct) run multidict 4.5.0, which has no C extension build for + # Python 3.10+ and runs as pure Python there; the other lanes run the compiled 6.x. + "multidict>=4.5,<7", # 0.7.3 is the first loguru release that imports without a DeprecationWarning on # Python 3.14: earlier ones call asyncio.iscoroutinefunction, which 3.16 removes. "loguru>=0.7.3,<1", @@ -242,6 +248,14 @@ 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, or through the standard logging module, would skip +# the SDK's log level and label, and the replacement of the API key with [REDACTED] +# (PER-16680). The whole logging module is banned: logging.info() and the like log to +# the root logger without a getLogger() call. +"loguru.logger".msg = "Log through permit.utils.sdk_logger, which redacts the API key." +"logging".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 +285,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" = [ diff --git a/tests/test_fix_logging.py b/tests/test_fix_logging.py new file mode 100644 index 00000000..505b0f95 --- /dev/null +++ b/tests/test_fix_logging.py @@ -0,0 +1,1988 @@ +"""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 builtins +import dataclasses +import importlib +import inspect +import json +import os +import pprint +import re +import socket +import socketserver +import subprocess +import sys +import threading +import traceback +import types +from collections.abc import Callable, Iterator +from dataclasses import dataclass, field +from pathlib import Path +from typing import Any, NoReturn, cast + +import aiohttp +import pytest +from aiohttp import http_parser +from loguru import logger +from multidict import CIMultiDict, CIMultiDictProxy +from pytest_httpserver import HTTPServer +from werkzeug import Request, Response +from yarl import URL + +import permit.logger as permit_logger +from permit import Permit, PermitConfig +from permit.enforcement.enforcer import CheckQuery +from permit.exceptions import PermitApiError, PermitConnectionError, scrub_request_info +from permit.sync import Permit as SyncPermit +from permit.utils.sdk_logger import REDACTED, SdkLogger, sdk_logger, without_userinfo + +SENTINEL = "permit_key_SENTINEL_9f8e7d6c5b4a39281706f5e4d3c2b1a0" +# The key as given and as aiohttp lower-cases it in some of its error messages. +SENTINEL_SPELLINGS = (SENTINEL, SENTINEL.lower()) +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(monkeypatch: pytest.MonkeyPatch) -> Iterator[None]: + """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. + """ + monkeypatch.setattr(permit_logger, "_warned_levels", set()) + 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: + 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) + + +async def use_client(permit: Permit) -> None: + """`use_async_client` or `use_sync_client`, whichever fits the client.""" + if isinstance(permit, SyncPermit): + use_sync_client(permit) + else: + await use_async_client(permit) + + +async def resolved(result: object) -> object: + """The value of an SDK call: awaited for the async client, as is for the blocking one.""" + return await result if inspect.isawaitable(result) else result + + +CLIENT_CLASSES = [pytest.param(Permit, id="async"), pytest.param(SyncPermit, id="sync")] + + +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) + + +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("client_class", CLIENT_CLASSES) +@pytest.mark.parametrize( + ("log", "application_enables", "logs_the_error"), + [ + pytest.param({"enable": True, "level": "trace"}, False, True, id="trace"), + pytest.param({"enable": True, "level": "debug"}, False, True, id="debug"), + pytest.param({"enable": True, "level": "info"}, False, True, id="info"), + pytest.param({"enable": True, "level": "error"}, False, True, id="error"), + pytest.param({"enable": True, "level": "critical"}, False, False, id="critical"), + pytest.param({"enable": False}, False, False, id="disabled"), + # A client created with logging disabled, whose records the application turns on. + pytest.param({"enable": False}, True, True, id="disabled-application-enables"), + ], +) +async def test_an_api_key_the_pdp_echoes_back_is_redacted( + httpserver: HTTPServer, + app_sinks: AppSinks, + client_class: type[Permit], + log: dict[str, Any], + *, + application_enables: bool, + logs_the_error: bool, +) -> None: + httpserver.expect_request("/allowed", method="POST").respond_with_handler(echo_the_key) + permit = client_class(make_config(httpserver, **log)) + if application_enables: + logger.enable("permit") + + with pytest.raises(PermitConnectionError) as raised: + await resolved(permit.check("user-1", "read", "document")) + + errors = [record for record in app_sinks.sdk_records() if record["level"]["name"] == "ERROR"] + if logs_the_error: + [record] = errors + assert f"rejected key: Bearer {REDACTED}" in record["message"] + else: + assert app_sinks.sdk_records() == [] + 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( + 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() + + +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"), + [ + 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"), + pytest.param({"level": "fatal"}, set(), id="fatal"), + ], +) +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_level_drops_the_sdk_records_below_it( + httpserver: HTTPServer, + app_sinks: AppSinks, + client_class: type[Permit], + log: dict[str, str], + expected_levels: set[str], +) -> None: + serve(httpserver) + + await use_client(client_class(make_config(httpserver, enable=True, **log))) + logger.debug("an application record") + + assert app_sinks.sdk_levels() == expected_levels + # Each name is one loguru knows, or reads as one: none falls back to INFO. + assert [r for r in app_sinks.sdk_records() if "Unknown log level" in r["message"]] == [] + assert SENTINEL not in app_sinks.everything() + # 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()] + + +# "²" is a digit to str.isdigit, but not a number int() reads. +@pytest.mark.parametrize("level", ["verbose", "²"]) +async def test_an_unknown_level_warns_and_logs_at_info( + httpserver: HTTPServer, app_sinks: AppSinks, level: str +) -> None: + serve(httpserver) + + await use_async_client(Permit(make_config(httpserver, enable=True, level=level))) + + warnings = [ + record + for record in app_sinks.sdk_records() + if record["level"]["name"] == "WARNING" + and f"Unknown log level {level!r}" 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"} + # The label applies on this path too. + assert [r for r in app_sinks.sdk_records() if not r["message"].startswith("[Permit] ")] == [] + + +def test_the_traceback_of_a_failed_client_creation_hides_the_api_key( + 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) + try: + try: + SyncPermit(config) + except RuntimeError: + 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 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"), + [ + 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) + + +@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() + 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_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 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", CLIENT_CLASSES) +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: + 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 + + +def echo_the_key_as_json(request: Request) -> Response: + """An API that rejects the request and echoes the key it was sent, in a JSON body.""" + body = {"detail": f"rejected key: {request.headers['Authorization']}", "error_code": "x"} + return Response(json.dumps(body), status=403, content_type="application/json") + + +def json_escaped(text: str) -> str: + r"""`text` as JSON may spell it in a string: every character a `\u` escape. + + The key then appears only once the body is decoded, not in its raw text. + """ + return "".join(f"\\u{ord(char):04x}" for char in text) + + +def echo_the_key_in_a_list(request: Request) -> Response: + """An API that rejects the request and echoes the key it was sent, in a list of errors.""" + key = json_escaped(request.headers["Authorization"]) + body = f'{{"detail": [{{"msg": "bad key {key}"}}]}}' + return Response(body, status=422, content_type="application/json") + + +def redirect_to_user_2(_: Request) -> Response: + """A redirect the client follows, with its headers, to the user-2 URL.""" + return Response(status=307, headers={"Location": f"{USERS}/user-2"}) + + +@pytest.mark.parametrize( + "handler", + [echo_the_key, echo_the_key_as_json, echo_the_key_in_a_list], + ids=["text", "json", "json-list"], +) +async def test_api_and_pdp_api_errors_do_not_hold_an_echoed_key( + httpserver: HTTPServer, handler: Callable[[Request], Response] +) -> None: + """The REST API and the PDP's local API raise through `handle_api_error`.""" + serve(httpserver) + httpserver.expect_request(f"{USERS}/user-2", method="GET").respond_with_handler(handler) + httpserver.expect_request(f"{USERS}/moved", method="GET").respond_with_handler( + redirect_to_user_2 + ) + httpserver.expect_request("/local/role_assignments", method="GET").respond_with_handler(handler) + permit = Permit(make_config(httpserver)) + + raised: list[BaseException] = [] + for call in ( + permit.api.users.get("user-2"), + permit.api.users.get("moved"), + permit.pdp_api.role_assignments.list(), + ): + with pytest.raises((PermitApiError, PermitConnectionError)) as caught: + await call + raised.append(caught.value) + + # The redirect was followed, with the key: the redirect response keeps the request + # headers it was sent with. + [redirected] = [ + error for error in raised if isinstance(error, PermitApiError) and error.response.history + ] + assert redirected.response.history[0].status == 307 + for error in raised: + assert SENTINEL not in str(error) + assert SENTINEL not in repr(error) + assert REDACTED in str(error) + assert_holds_no_key(error) + + +def assert_holds_no_key(error: BaseException) -> None: + """Assert neither `error` nor the aiohttp objects it carries print the key. + + Those are its cause and context, `original_error`, a `PermitApiError`'s response and + details, the redirect responses in the `history` of any of them, and the traceback of + `error` with every exception chained under it. The key is looked for as given and in + lower case. + """ + shown = [ + str(error), + repr(error.args), + repr(getattr(error, "details", None)), + "".join(traceback.format_exception(error)), + ] + carried = [ + error.__cause__, + error.__context__, + getattr(error, "original_error", None), + getattr(error, "_response", None), + ] + carried += [redirect for value in carried for redirect in getattr(value, "history", None) or ()] + for value in carried: + shown += [repr(value), repr(getattr(value, "args", ()))] + info = getattr(value, "request_info", None) + if info is not None: + shown += [repr(info), str(dict(info.headers))] + # Every attribute of every chained exception, printed or not. + shown += [repr(vars(chained)) + repr(chained.args) for chained in chained_exceptions(error)] + for key in SENTINEL_SPELLINGS: + assert [text for text in shown if key in text] == [] + + +def chained_exceptions(error: BaseException) -> list[BaseException]: + """Every exception reachable from `error` through `__cause__` and `__context__`.""" + found: list[BaseException] = [] + pending: list[BaseException | None] = [error] + while pending: + current = pending.pop() + if current is not None and not any(current is seen for seen in found): + found.append(current) + pending += [current.__cause__, current.__context__] + return found + + +@pytest.mark.parametrize("status", [200, 502]) +async def test_a_non_json_answer_raises_without_the_key_in_its_request_headers( + httpserver: HTTPServer, status: int +) -> None: + """An answer that isn't JSON raises without the key in its request headers. + + aiohttp keeps the request's headers on the error it raises for it. The SDK's + exception, its cause and `original_error` don't print the key. + """ + # Not `serve`, which already answers /allowed with JSON. + 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(f"{USERS}/user-3", method="GET").respond_with_data( + "bad gateway", status=status, content_type="text/html" + ) + httpserver.expect_request("/allowed", method="POST").respond_with_data( + "proxy", status=200, content_type="text/html" + ) + permit = Permit(make_config(httpserver)) + + raised: list[BaseException] = [] + for call in (permit.api.users.get("user-3"), permit.check("user-1", "read", "document")): + with pytest.raises((PermitApiError, PermitConnectionError)) as caught: + await call + raised.append(caught.value) + + assert any(error.__cause__ is not None for error in raised) + for error in raised: + assert_holds_no_key(error) + + +@pytest.mark.parametrize( + ("url", "shown"), + [ + ("http://user:secret@pdp.example.com:7766/x", "http://pdp.example.com:7766/x"), + ("http://user:secret@[::1]:7766", "http://[::1]:7766"), + ("http://user:secret@pdp.example.com:99999", "http://pdp.example.com:99999"), + ("http://pdp.example.com:7766", "http://pdp.example.com:7766"), + ("http://[::1", ""), + ], +) +def test_without_userinfo_never_raises(url: str, shown: str) -> None: + assert without_userinfo(url) == shown + + +def test_the_init_line_leaves_out_the_url_user_and_password( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + url = httpserver.url_for("").rstrip("/").replace("://", "://proxy-user:proxy-password@") + config = PermitConfig( + token=SENTINEL, api_url=url, pdp=url, log={"enable": True, "level": "debug"} + ) + + SyncPermit(config) + + [record] = [r for r in app_sinks.sdk_records() if "SDK initialized" in r["message"]] + assert "proxy-password" not in record["message"] + assert "proxy-user" not in record["message"] + assert httpserver.url_for("").rstrip("/") in record["message"] + + +def test_wait_for_sync_runs_a_subclass_s_own_setup(httpserver: HTTPServer) -> None: + class CustomPermit(SyncPermit): + def __init__(self, config: PermitConfig) -> None: + super().__init__(config) + self.custom = True + + permit = CustomPermit(proxied_config(httpserver)) + with permit.wait_for_sync() as waiting: + assert type(waiting) is CustomPermit + assert waiting.custom is True + + +def test_a_short_token_is_not_redacted_from_the_sdk_s_text() -> None: + redactor = SdkLogger() + redactor.redact("token") + redactor.redact(" permit ") + + assert redactor.scrub("bad token for permit.check()") == "bad token for permit.check()" + + +def test_a_key_of_12_characters_is_redacted_and_one_of_11_is_not() -> None: + redactor = SdkLogger() + redactor.redact("a" * 11) + redactor.redact("b" * 12) + + assert redactor.scrub(f"{'a' * 11} {'b' * 12}") == f"{'a' * 11} {REDACTED}" + + +@pytest.mark.parametrize("level", ["10", " debug ", "DEBUG"]) +def test_a_numeric_or_padded_level_is_read( + httpserver: HTTPServer, app_sinks: AppSinks, level: str +) -> None: + httpserver.expect_request("/allowed", method="POST").respond_with_json({"allow": True}) + permit = SyncPermit(make_config(httpserver, enable=True, level=level)) + + assert permit.check("user-1", "read", "document") + + levels = {record["level"]["name"] for record in app_sinks.sdk_records()} + assert "DEBUG" in levels + assert "WARNING" not in levels + + +def test_an_unknown_level_is_warned_about_once(httpserver: HTTPServer, app_sinks: AppSinks) -> None: + for _ in range(3): + # The name test_an_unknown_level_warns_and_logs_at_info uses too: each test starts + # with no name warned about. + SyncPermit(make_config(httpserver, enable=True, level="verbose")) + + warnings = [r for r in app_sinks.sdk_records() if "Unknown log level" in r["message"]] + assert len(warnings) == 1 + + +def echo_the_key_as_a_json_object_key(request: Request) -> Response: + """An API that rejects the request and puts the key it was sent in an object key.""" + key = json_escaped(request.headers["Authorization"]) + body = f'{{"detail": {{"{key}": "rejected"}}, "error_code": "x"}}' + return Response(body, status=403, content_type="application/json") + + +async def test_an_echoed_key_in_a_json_object_key_is_redacted(httpserver: HTTPServer) -> None: + serve(httpserver) + httpserver.expect_request(f"{USERS}/user-4", method="GET").respond_with_handler( + echo_the_key_as_a_json_object_key + ) + permit = Permit(make_config(httpserver)) + + with pytest.raises(PermitApiError) as caught: + await permit.api.users.get("user-4") + + assert SENTINEL not in str(caught.value) + assert SENTINEL not in repr(caught.value.details) + + +def test_a_key_in_the_label_is_redacted(httpserver: HTTPServer, app_sinks: AppSinks) -> None: + config = make_config(httpserver, enable=True, level="debug", label=f"app {SENTINEL}") + + SyncPermit(config) + + records = app_sinks.sdk_records() + assert records + for record in records: + assert SENTINEL not in record["message"] + + +@pytest.mark.parametrize( + "body", + [ + pytest.param(lambda auth: f"rejected key {auth}".encode(), id="html"), + pytest.param(lambda auth: f'{{"detail": "rejected key {auth}"'.encode(), id="truncated"), + pytest.param(lambda auth: b"\xff rejected key " + auth.encode(), id="not-utf-8"), + ], +) +async def test_an_error_body_labelled_json_that_is_not_json_raises_a_permit_api_error( + httpserver: HTTPServer, body: Callable[[str], bytes] +) -> None: + serve(httpserver) + + def handler(request: Request) -> Response: + return Response( + body(request.headers["Authorization"]), + status=502, + content_type="application/json; charset=utf-8", + ) + + httpserver.expect_request(f"{USERS}/user-6", method="GET").respond_with_handler(handler) + permit = Permit(make_config(httpserver)) + + with pytest.raises(PermitApiError) as caught: + await permit.api.users.get("user-6") + + assert caught.value.status_code == 502 + assert caught.value.details is not None + assert f"rejected key Bearer {REDACTED}" in caught.value.details["details"] + assert_holds_no_key(caught.value) + + +def answer_with_the_key_in_the_content_type(request: Request) -> Response: + """A 200 answer that isn't JSON, its Content-Type echoing the key the request carried. + + The key is echoed without surrounding whitespace. + """ + key = request.headers["Authorization"].removeprefix("Bearer ").strip() + return Response("not json", status=200, content_type=f"text/html; echo={key}") + + +# A key read from a file may end with a space, which the echo drops. +@pytest.mark.parametrize("token", [SENTINEL, f"{SENTINEL} "], ids=["key", "padded-key"]) +async def test_a_connection_error_holds_no_key_from_the_aiohttp_error_text( + httpserver: HTTPServer, token: str +) -> None: + """The text of an aiohttp error goes into the message of the PermitConnectionError. + + aiohttp lower-cases the Content-Type it puts in the message of the error it raises for + an answer that isn't JSON, so the key, which has capital letters, is there in lower case. + """ + for path in ("/allowed", "/allowed/bulk", "/authorized_users", "/user-permissions"): + httpserver.expect_request(path, method="POST").respond_with_handler( + answer_with_the_key_in_the_content_type + ) + httpserver.expect_request(f"{USERS}/user-7", method="GET").respond_with_handler( + answer_with_the_key_in_the_content_type + ) + # After the handlers above: the first one registered for a request answers it. + serve(httpserver) + permit = Permit(make_config(httpserver, token=token)) + sync_permit = SyncPermit(make_config(httpserver, token=token)) + + calls: list[Callable[[], Any]] = [ + lambda: permit.check("user-1", "read", "document"), + lambda: permit.bulk_check(BULK), + lambda: permit.authorized_users("read", "document"), + lambda: permit.get_user_permissions("user-1"), + lambda: permit.api.users.get("user-7"), + ] + raised: list[PermitConnectionError] = [] + for call in calls: + with pytest.raises(PermitConnectionError) as caught: + await call() + raised.append(caught.value) + with pytest.raises(PermitConnectionError) as caught: + sync_permit.check("user-1", "read", "document") + raised.append(caught.value) + + for error in raised: + # The aiohttp error's text is in the message, the key replaced. + assert f"echo={REDACTED}" in str(error) + assert_holds_no_key(error) + # The key is replaced in the response headers the error keeps, so it is attached. + assert isinstance(error.original_error, aiohttp.ContentTypeError) + + +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +def test_a_subclass_s_own_connect_method_is_not_called_by_the_sdk( + httpserver: HTTPServer, client_class: type[Permit] +) -> None: + """The SDK's constructor calls no method an application's subclass may define.""" + + class AppPermit(client_class): # type: ignore[valid-type,misc] + def _connect(self, url: str) -> str: + return url + + permit = AppPermit(make_config(httpserver)) + + assert permit.api is not None + assert permit._connect("x") == "x" + + +def test_an_enabled_client_undoes_only_the_sdk_s_own_disable_once( + httpserver: HTTPServer, app_sinks: AppSinks +) -> None: + SyncPermit(make_config(httpserver)) + # Undoes the disable the client above made. + SyncPermit(make_config(httpserver, enable=True)) + logger.disable("permit") + + # The SDK's own disable was undone already: this one keeps the application's. + with SyncPermit(make_config(httpserver, enable=True)).wait_for_sync(): + pass + + assert app_sinks.sdk_records() == [] + + +@pytest.mark.parametrize("disabled", ["permit.enforcement", ""], ids=["sdk-module", "all"]) +def test_undoing_the_sdk_s_disable_undoes_a_disable_the_application_made_before_it( + httpserver: HTTPServer, app_sinks: AppSinks, disabled: str +) -> None: + """Loguru's `logger.disable("permit")` drops every switch set for a module of it. + + So does `logger.enable("permit")`, which the enabled client calls to undo it, and it + overrides an application-wide `logger.disable("")` for the SDK's records. The README + says so. + """ + httpserver.expect_request("/allowed", method="POST").respond_with_json({"allow": True}) + logger.disable(disabled) + try: + SyncPermit(make_config(httpserver)) + permit = SyncPermit(make_config(httpserver, enable=True, level="debug")) + assert permit.check("user-1", "read", "document") + finally: + logger.enable(disabled) + + modules = {record["name"] for record in app_sinks.sdk_records()} + assert "permit.enforcement.enforcer" in modules + + +LAZY_DEBUG_CALLS: list[Any] = [ + pytest.param(lambda permit: permit.check("user-1", "read", "document"), id="check"), + pytest.param(lambda permit: permit.bulk_check(BULK), id="bulk_check"), + pytest.param(lambda permit: permit.authorized_users("read", "document"), id="authorized_users"), + pytest.param(lambda permit: permit.get_user_permissions("user-1"), id="get_user_permissions"), +] + + +@pytest.mark.parametrize("call", LAZY_DEBUG_CALLS) +@pytest.mark.parametrize("application_enables", [False, True]) +def test_a_record_loguru_drops_is_not_built_or_scrubbed( + httpserver: HTTPServer, + app_sinks: AppSinks, + monkeypatch: pytest.MonkeyPatch, + call: Callable[[SyncPermit], object], + *, + application_enables: bool, +) -> None: + """With the SDK's logging off, its debug records cost nothing to drop. + + The application may still turn them on itself, and then gets them in full. + """ + httpserver.expect_request("/allowed", method="POST").respond_with_json({"allow": True}) + httpserver.expect_request("/allowed/bulk", method="POST").respond_with_json( + {"allow": [{"allow": True}]} + ) + httpserver.expect_request("/authorized_users", method="POST").respond_with_json( + {"resource": "document:*", "tenant": "default", "users": {}} + ) + httpserver.expect_request("/user-permissions", method="POST").respond_with_json({}) + calls: list[str] = [] + real_scrub = sdk_logger.scrub + + def pformat(value: object, **kwargs: Any) -> str: + calls.append("pformat") + return pprint.pformat(value, **kwargs) + + def scrub(text: str) -> str: + calls.append("scrub") + return real_scrub(text) + + monkeypatch.setattr("permit.enforcement.enforcer.pformat", pformat) + monkeypatch.setattr(sdk_logger, "scrub", scrub) + client = SyncPermit(make_config(httpserver)) + if application_enables: + logger.enable("permit") + + call(client) + + if application_enables: + [record] = app_sinks.sdk_records() + assert record["level"]["name"] == "DEBUG" + assert "pformat" in calls + assert "scrub" in calls + else: + assert app_sinks.sdk_records() == [] + assert calls == [] + + +@pytest.mark.parametrize("message", [None, 42, b"bytes", ValueError("x")], ids=repr) +def test_a_connection_error_keeps_a_message_that_is_not_a_string( + httpserver: HTTPServer, message: object +) -> None: + Permit(make_config(httpserver)) + + error = PermitConnectionError(message) + + assert error.args == (message,) + + +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_a_pdp_error_body_that_is_not_utf_8_raises_a_permit_connection_error( + httpserver: HTTPServer, client_class: type[Permit] +) -> None: + def handler(request: Request) -> Response: + body = b"\xff rejected key: " + request.headers["Authorization"].encode() + return Response(body, status=403, content_type="text/plain; charset=utf-8") + + for path in ("/allowed", "/allowed/bulk", "/authorized_users"): + httpserver.expect_request(path, method="POST").respond_with_handler(handler) + permit = client_class(make_config(httpserver)) + + 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 caught: + await resolved(call()) + assert f"rejected key: Bearer {REDACTED}" in str(caught.value) + assert_holds_no_key(caught.value) + + +class _RawHandler(socketserver.StreamRequestHandler): + """Answers a request with the server's raw bytes, then closes the connection.""" + + def handle(self) -> None: + # The request line and headers; any body is left unread. + line = self.rfile.readline() + while line not in (b"\r\n", b"\n", b""): + line = self.rfile.readline() + self.wfile.write(cast("_RawHttpServer", self.server).reply) + + +class _RawHttpServer(socketserver.ThreadingTCPServer): + daemon_threads = True + allow_reuse_address = True + + def __init__(self, reply: bytes) -> None: + super().__init__(("127.0.0.1", 0), _RawHandler) + self.reply = reply + + +EMPTY = "Content-Length: 0\r\n\r\n" + + +def redirect_to(location: str) -> str: + return f"HTTP/1.1 307 TR\r\nLocation: {location}\r\n{EMPTY}" + + +LONG = "a" * 9000 + +# Answers aiohttp can't use, each holding the key. aiohttp keeps the key in the text of +# the error it raises (its message, its args or its URL), or in the parser error it chains +# under it, as a string, as bytes or as a yarl URL. +RAW_ANSWERS = [ + pytest.param( + "HTTP/1.1 200 OK\r\nContent-Length: 2\r\nBad Header {key}: x\r\n\r\nok", id="bad-header" + ), + pytest.param("HTTP/1.1 abc {key}\r\n" + EMPTY, id="bad-status-line"), + # LineTooLong, which keeps the line as bytes in its args. + pytest.param("HTTP/1.1 200 OK\r\nX-Long: {key}" + LONG + "\r\n" + EMPTY, id="header-too-long"), + # InvalidHeader, which keeps the header as bytes in its args. + pytest.param("HTTP/1.1 200 OK\r\nX-Nul: {key}\x00\r\n" + EMPTY, id="nul-in-header"), + pytest.param(redirect_to("http://[{key}"), id="invalid-redirect-url"), + # InvalidUrlRedirectClientError with the URL parsed: a yarl URL in `_url` and `args`. + pytest.param(redirect_to("http:///{key}"), id="redirect-url-without-host"), + pytest.param(redirect_to("ftp://host/{key}"), id="non-http-redirect"), + # A ValueError raised in yarl, which keeps the host in its message. + pytest.param(redirect_to("http://{key}\u200bx/"), id="zero-width-space-in-redirect-host"), +] + + +@pytest.fixture +def raw_http_server(request: pytest.FixtureRequest) -> Iterator[str]: + """A server that answers with `request.param`, the key put in it; yields its URL.""" + server = _RawHttpServer(request.param.format(key=SENTINEL).encode()) + # A short poll interval: shutdown() waits for the next poll. + thread = threading.Thread(target=server.serve_forever, args=(0.01,), daemon=True) + thread.start() + yield f"http://127.0.0.1:{server.server_address[1]}" + server.shutdown() + server.server_close() + + +@pytest.mark.parametrize("raw_http_server", RAW_ANSWERS, indirect=True) +@pytest.mark.parametrize( + "call", + [ + pytest.param(lambda permit: permit.check("user-1", "read", "document"), id="pdp"), + pytest.param(lambda permit: permit.api.users.get("user-1"), id="api"), + ], +) +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_an_aiohttp_error_and_the_errors_chained_under_it_hold_no_key( + raw_http_server: str, client_class: type[Permit], call: Callable[[Permit], object] +) -> None: + permit = client_class( + PermitConfig(token=SENTINEL, api_url=raw_http_server, pdp=raw_http_server) + ) + + with pytest.raises(PermitConnectionError) as caught: + await resolved(call(permit)) + + assert caught.value.original_error is not None + assert_holds_no_key(caught.value) + # The case still reaches a key to replace, in the aiohttp error or under it. + shown = [ + repr(vars(chained)) + repr(chained.args) + for chained in chained_exceptions(caught.value.original_error) + ] + assert REDACTED in "".join(shown) + + +# Functions that raise and catch in a module of aiohttp's, as aiohttp's own code does: the +# SDK changes only exceptions raised and caught within its request. +AIOHTTP_DOUBLE_SOURCE = """ +import aiohttp + + +def context_only(key): + try: + try: + raise ValueError(f"inner {key}") + except ValueError: + raise aiohttp.ClientError("outer") + except aiohttp.ClientError as error: + return error + + +def raised(error): + try: + raise error + except BaseException as caught: + return caught + + +def calling(function): + try: + function() + except BaseException as caught: + return caught +""" +aiohttp_double = types.ModuleType("aiohttp._test_double") +exec(AIOHTTP_DOUBLE_SOURCE, aiohttp_double.__dict__) # noqa: S102 - a fixed test double + + +def test_an_error_chained_only_as_the_context_is_scrubbed(httpserver: HTTPServer) -> None: + Permit(make_config(httpserver)) + error = aiohttp_double.context_only(SENTINEL) + inner = error.__context__ + assert error.__cause__ is None + assert isinstance(inner, ValueError) + + assert scrub_request_info(error) + + assert inner.args == (f"inner {REDACTED}",) + + +# A walk that never ends can't be stopped in a thread, so this runs in its own process. +CAUSE_CYCLE_APP = f""" +import sys +import types + +import aiohttp + +from permit import Permit +from permit.exceptions import scrub_request_info + +double = types.ModuleType("aiohttp._test_double") +exec({AIOHTTP_DOUBLE_SOURCE!r}, double.__dict__) +Permit(token="{SENTINEL}") +first = double.raised(aiohttp.ClientError("first {SENTINEL}")) +second = double.raised(aiohttp.ClientError("second {SENTINEL}")) +first.__cause__ = second +second.__cause__ = first +assert scrub_request_info(first) +print(first.args[0], second.args[0]) +# A cycle of exceptions the SDK leaves as it is, which it only checks for the key. +left = ValueError("left") +left.__cause__ = ValueError("under it") +left.__cause__.__cause__ = left +outer = double.raised(aiohttp.ClientError("outer")) +outer.__cause__ = left +print(scrub_request_info(outer)) +""" + + +def test_a_cause_cycle_is_walked_once(tmp_path: Path) -> None: + app = tmp_path / "app.py" + app.write_text(CAUSE_CYCLE_APP) + + result = subprocess.run( + [sys.executable, str(app)], capture_output=True, text=True, timeout=15, check=False + ) + + assert result.returncode == 0, result.stderr + assert result.stdout.split() == ["first", REDACTED, "second", REDACTED, "True"] + + +def test_an_error_whose_text_cannot_be_replaced_is_not_attached(httpserver: HTTPServer) -> None: + class FixedArgsError(aiohttp.ClientError): + @property + def args(self) -> tuple[object, ...]: # type: ignore[override] + return (f"fixed {SENTINEL}",) + + Permit(make_config(httpserver)) + original = aiohttp_double.raised(FixedArgsError()) + + error = PermitConnectionError("the request failed", error=original) + + assert error.original_error is not original + assert SENTINEL not in repr(error.original_error) + assert "could not be removed" in str(error.original_error) + + +class _FixedRequestInfoError(aiohttp.ClientError): + """An aiohttp error whose `request_info` can't be replaced, and which its text doesn't show.""" + + @property + def request_info(self) -> aiohttp.RequestInfo: + url = URL("http://127.0.0.1/") + headers = CIMultiDictProxy(CIMultiDict({"Authorization": f"Bearer {SENTINEL}"})) + return aiohttp.RequestInfo(url, "GET", headers, url) + + +def test_an_error_whose_request_headers_cannot_be_replaced_is_not_attached( + httpserver: HTTPServer, +) -> None: + Permit(make_config(httpserver)) + original = aiohttp_double.raised(_FixedRequestInfoError()) + + error = PermitConnectionError("the request failed", error=original) + + assert "could not be removed" in str(error.original_error) + + +@dataclasses.dataclass(frozen=True) +class _FrozenRequestError(Exception): + """An exception that can't be changed, with text and headers that hold no key.""" + + detail: str + headers: dict[str, str] + + +def test_an_error_without_the_key_is_not_written_to(httpserver: HTTPServer) -> None: + Permit(make_config(httpserver)) + original = aiohttp_double.raised(aiohttp.ClientError("outer")) + original.__cause__ = aiohttp_double.raised(_FrozenRequestError("no key", {"X-Id": "1"})) + + error = PermitConnectionError("the request failed", error=original) + + # Nothing is written to it: a write would fail, and the error wouldn't be attached. + assert error.original_error is original + + +def raise_(error: BaseException) -> NoReturn: + raise error + + +@dataclasses.dataclass(frozen=True) +class FrozenAppError(Exception): + """An application's exception that can't be changed.""" + + detail: str + + +class AppHeadersError(Exception): + """An application's exception with a headers dict whose values aren't all strings.""" + + def __init__(self) -> None: + super().__init__(f"the application's own text, with the key {SENTINEL}") + self.headers = {"Retry-After": 120, "X-Echo": SENTINEL} + + +class AppFixedArgsError(Exception): + """An application's exception whose args can't be set.""" + + @property + def args(self) -> tuple[object, ...]: # type: ignore[override] + return (f"fixed {SENTINEL}",) + + +@pytest.mark.parametrize( + "app_error", + [ + pytest.param(lambda: FrozenAppError(f"frozen {SENTINEL}"), id="frozen-dataclass"), + pytest.param(AppHeadersError, id="headers-with-an-int"), + pytest.param(AppFixedArgsError, id="read-only-args"), + ], +) +@pytest.mark.parametrize( + "call", + [*LAZY_DEBUG_CALLS, pytest.param(lambda permit: permit.api.users.get("user-1"), id="api")], +) +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +@pytest.mark.parametrize( + "raw_http_server", [pytest.param(redirect_to("ftp://host/{key}"), id="redirect")], indirect=True +) +async def test_an_exception_the_application_is_handling_is_left_alone( + raw_http_server: str, + client_class: type[Permit], + call: Callable[[Permit], object], + app_error: Callable[[], Exception], +) -> None: + """An application may call the SDK while it handles an exception of its own. + + aiohttp's error then keeps that exception as its context: here, the error for a + redirect to a URL that isn't HTTP, which aiohttp raises in the caller's task. The SDK + still raises PermitConnectionError, and doesn't change the application's exception, + even where it holds the key. + """ + url = raw_http_server + permit = client_class(PermitConfig(token=SENTINEL, api_url=url, pdp=url)) + handled = app_error() + before = (repr(vars(handled)), repr(handled.args)) + + try: + raise_(handled) + except Exception: + with pytest.raises(PermitConnectionError) as caught: + await resolved(call(permit)) + + # The application's exception is in the chain, unchanged. + assert any(chained is handled for chained in chained_exceptions(caught.value)) + assert (repr(vars(handled)), repr(handled.args)) == before + if isinstance(handled, AppHeadersError): + assert type(handled.headers) is dict + # The aiohttp error is attached: the application's exception, which holds the key, + # doesn't make the SDK fail closed. + assert caught.value.original_error is not None + assert "not attached" not in str(caught.value.original_error) + assert SENTINEL not in repr(vars(caught.value.original_error)) + + +@pytest.mark.parametrize( + "raw_http_server", [pytest.param(redirect_to("ftp://host/{key}"), id="redirect")], indirect=True +) +@pytest.mark.parametrize( + "call", + [*LAZY_DEBUG_CALLS, pytest.param(lambda permit: permit.api.users.get("user-1"), id="api")], +) +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_an_error_that_cannot_be_scrubbed_is_neither_attached_nor_the_cause( + raw_http_server: str, + client_class: type[Permit], + call: Callable[[Permit], object], + monkeypatch: pytest.MonkeyPatch, +) -> None: + monkeypatch.setattr("permit.exceptions.scrub_request_info", lambda *_, **__: False) + url = raw_http_server + permit = client_class(PermitConfig(token=SENTINEL, api_url=url, pdp=url)) + + with pytest.raises(PermitConnectionError) as caught: + await resolved(call(permit)) + + replacement = caught.value.original_error + assert "could not be removed" in str(replacement) + assert caught.value.__cause__ is replacement + # Nor is the error that wasn't attached its context. + assert not any( + isinstance(chained, aiohttp.ClientError) and chained is not replacement + for chained in chained_exceptions(caught.value) + ) + assert SENTINEL not in "".join(traceback.format_exception(caught.value)) + + +def closed_port() -> int: + """A port on 127.0.0.1 nothing listens on: a connection to it is refused.""" + with socket.socket() as probe: + probe.bind(("127.0.0.1", 0)) + return cast("int", probe.getsockname()[1]) + + +class AppStringHeadersError(Exception): + """An application's exception with a headers dict of strings, one holding the key.""" + + def __init__(self) -> None: + super().__init__(f"the application's own text, with the key {SENTINEL}") + self.headers = {"X-Echo": SENTINEL} + + +@pytest.mark.parametrize( + "call", + [*LAZY_DEBUG_CALLS, pytest.param(lambda permit: permit.api.users.get("user-1"), id="api")], +) +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_an_exception_the_application_is_handling_is_left_alone_on_a_refused_connection( + client_class: type[Permit], call: Callable[[Permit], object] +) -> None: + """A refused connection's `OSError` keeps the application's exception as its context. + + That is where the connection is refused at once, in the caller's task, as on Linux. + Where the refusal comes later from the event loop, as on macOS, the chain doesn't hold + it, and the redirect cases above are the ones that check this. + """ + url = f"http://127.0.0.1:{closed_port()}" + permit = client_class(PermitConfig(token=SENTINEL, api_url=url, pdp=url)) + handled = AppStringHeadersError() + headers = handled.headers + before = (repr(vars(handled)), repr(handled.args)) + + try: + raise_(handled) + except Exception: + with pytest.raises(PermitConnectionError) as caught: + await resolved(call(permit)) + + assert handled.headers is headers + assert (repr(vars(handled)), repr(handled.args)) == before + assert caught.value.original_error is not None + assert "not attached" not in str(caught.value.original_error) + + +@pytest.mark.parametrize( + "raw_http_server", + # yarl's IDNA encoding of the host fails in `idna`, a package the SDK doesn't change + # exceptions of, and that error keeps the host in its args. + [pytest.param(redirect_to("http://{key}ü..x/"), id="idna-error-in-a-redirect-host")], + indirect=True, +) +@pytest.mark.parametrize( + "call", + [ + pytest.param(lambda permit: permit.check("user-1", "read", "document"), id="pdp"), + pytest.param(lambda permit: permit.api.users.get("user-1"), id="api"), + ], +) +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_an_error_left_as_it_is_that_holds_the_key_is_not_attached( + raw_http_server: str, client_class: type[Permit], call: Callable[[Permit], object] +) -> None: + url = raw_http_server + permit = client_class(PermitConfig(token=SENTINEL, api_url=url, pdp=url)) + + with pytest.raises(PermitConnectionError) as caught: + await resolved(call(permit)) + + assert "could not be removed" in str(caught.value.original_error) + assert caught.value.__cause__ is caught.value.original_error + assert_holds_no_key(caught.value) + + +def test_the_pure_python_parser_is_in_use() -> None: + if os.environ.get("AIOHTTP_NO_EXTENSIONS") != "1": + pytest.skip("runs from test_the_raw_answers_hold_no_key_on_the_pure_python_parser") + + assert http_parser.HttpResponseParser is http_parser.HttpResponseParserPy + + +@pytest.mark.skipif( + os.environ.get("AIOHTTP_NO_EXTENSIONS") == "1", reason="this run already uses that parser" +) +def test_the_raw_answers_hold_no_key_on_the_pure_python_parser() -> None: + """The raw answers' cases, on the parser aiohttp uses when told not to use its C one. + + The two parsers' errors keep the server's text in different places. + """ + selected = [ + "test_the_pure_python_parser_is_in_use", + "test_an_aiohttp_error_and_the_errors_chained_under_it_hold_no_key", + "test_an_error_left_as_it_is_that_holds_the_key_is_not_attached", + ] + result = subprocess.run( + [ + sys.executable, + "-m", + "pytest", + __file__, + "-q", + "-p", + "no:cacheprovider", + "-k", + " or ".join(selected), + ], + env={**os.environ, "AIOHTTP_NO_EXTENSIONS": "1"}, + cwd=Path(__file__).parents[1], + capture_output=True, + text=True, + timeout=300, + check=False, + ) + + assert result.returncode == 0, result.stdout + result.stderr + passed = re.search(r"(\d+) passed", result.stdout) + assert passed is not None, result.stdout + assert int(passed.group(1)) == 1 + (len(RAW_ANSWERS) + 1) * 4, result.stdout + + +class _FixedArgsClientError(aiohttp.ClientError): + @property + def args(self) -> tuple[object, ...]: # type: ignore[override] + return (f"fixed {SENTINEL}",) + + +def test_a_bytearray_an_error_keeps_is_scrubbed(httpserver: HTTPServer) -> None: + Permit(make_config(httpserver)) + error = aiohttp_double.raised(aiohttp.ClientError(bytearray(f"line {SENTINEL}".encode()))) + + assert scrub_request_info(error) + + assert error.args == (bytearray(f"line {REDACTED}".encode()),) + + +def test_a_scrub_that_raises_reports_failure() -> None: + class HistoryRaises: + @property + def history(self) -> NoReturn: + raise RuntimeError(self) + + assert scrub_request_info(HistoryRaises()) is False + + +def test_the_errors_after_one_that_cannot_be_scrubbed_still_are(httpserver: HTTPServer) -> None: + Permit(make_config(httpserver)) + outer = aiohttp_double.raised(_FixedArgsClientError()) + inner = aiohttp_double.raised(aiohttp.ClientError(f"inner {SENTINEL}")) + outer.__cause__ = inner + + assert not scrub_request_info(outer) + + assert inner.args == (f"inner {REDACTED}",) + + +def test_text_a_builtin_exception_keeps_outside_its_args_fails_the_scrub( + httpserver: HTTPServer, +) -> None: + Permit(make_config(httpserver)) + outer = aiohttp_double.raised(aiohttp.ClientError("outer")) + undecodable = f"{SENTINEL}\xff".encode("latin-1") + outer.__cause__ = aiohttp_double.raised( + UnicodeDecodeError("utf-8", undecodable, len(SENTINEL), len(SENTINEL) + 1, "invalid") + ) + + # Its args are replaced, but its `object` can't be reached that way. + assert not scrub_request_info(outer) + + +def raise_application_error() -> NoReturn: + raise_(ValueError(f"the application's {SENTINEL}")) + + +def application_error_raised_from_aiohttp() -> BaseException: + # The first frame is aiohttp's, the frame that raised it the application's. + return cast("BaseException", aiohttp_double.calling(raise_application_error)) + + +def application_error_never_raised() -> BaseException: + return ValueError(f"the application's {SENTINEL}") + + +def key_held_under_an_application_error() -> BaseException: + middle = aiohttp_double.calling(lambda: raise_(ValueError("the application's"))) + middle.__cause__ = aiohttp_double.raised(aiohttp.ClientError(f"under it {SENTINEL}")) + return cast("BaseException", middle) + + +# A builtin from Python 3.11; on Python 3.10, the backport that pytest depends on there. +EXCEPTION_GROUP: Any = ( + getattr(builtins, "ExceptionGroup", None) + or importlib.import_module("exceptiongroup").ExceptionGroup +) + + +class _EchoClientError(aiohttp.ClientError): + """An aiohttp error with text in an attribute of its own, which its repr doesn't show.""" + + def __init__(self, echo: str) -> None: + super().__init__("echo") + self.echo = echo + + +class _ShowsTheKeyError(Exception): + """An exception whose text holds the key, which neither its args nor its attributes do.""" + + def __str__(self) -> str: + return f"shown {SENTINEL}" + + +def key_only_in_the_text_of_an_application_error() -> BaseException: + return cast("BaseException", aiohttp_double.calling(lambda: raise_(_ShowsTheKeyError()))) + + +class _HidesItsArgsError(Exception): + """An exception whose text doesn't show its args.""" + + def __str__(self) -> str: + return "hidden" + + +def key_only_in_the_args_of_an_application_error() -> BaseException: + error = _HidesItsArgsError(f"Bearer {SENTINEL}") + return cast("BaseException", aiohttp_double.calling(lambda: raise_(error))) + + +def key_held_under_a_member_of_a_group() -> BaseException: + # The group is raised within the request, its member by the application. + member = key_held_under_an_application_error() + return cast("BaseException", aiohttp_double.raised(EXCEPTION_GROUP("group", [member]))) + + +def key_held_in_a_member_of_an_application_group() -> BaseException: + member = aiohttp_double.raised(_EchoClientError(f"Bearer {SENTINEL}")) + group = EXCEPTION_GROUP("the application's", [member]) + return cast("BaseException", aiohttp_double.calling(lambda: raise_(group))) + + +@pytest.mark.parametrize( + "under", + [ + pytest.param(application_error_raised_from_aiohttp, id="a-frame-of-the-applications"), + pytest.param(application_error_never_raised, id="no-traceback"), + pytest.param(key_held_under_an_application_error, id="the-key-under-it"), + pytest.param(key_only_in_the_text_of_an_application_error, id="the-key-in-its-text"), + pytest.param(key_only_in_the_args_of_an_application_error, id="the-key-in-its-args"), + pytest.param(key_held_under_a_member_of_a_group, id="the-key-under-a-group-member"), + pytest.param(key_held_in_a_member_of_an_application_group, id="the-key-in-a-group-member"), + ], +) +def test_an_error_that_is_not_the_requests_is_left_as_it_is_and_fails_the_scrub( + httpserver: HTTPServer, under: Callable[[], BaseException] +) -> None: + Permit(make_config(httpserver)) + outer = aiohttp_double.raised(aiohttp.ClientError("outer")) + outer.__cause__ = under() + before = [(repr(vars(chained)), repr(chained.args)) for chained in chained_exceptions(outer)] + + assert not scrub_request_info(outer) + + after = [(repr(vars(chained)), repr(chained.args)) for chained in chained_exceptions(outer)] + assert after == before + + +def test_the_members_of_an_exception_group_under_an_aiohttp_error_are_scrubbed( + httpserver: HTTPServer, +) -> None: + Permit(make_config(httpserver)) + member = aiohttp_double.raised(_EchoClientError(f"Bearer {SENTINEL}")) + member.__cause__ = aiohttp_double.raised(ValueError(f"under the member {SENTINEL}")) + outer = aiohttp_double.raised(aiohttp.ClientError("outer")) + outer.__cause__ = aiohttp_double.raised(EXCEPTION_GROUP("group", [member])) + + error = PermitConnectionError("the request failed", error=outer) + + assert error.original_error is outer + assert member.echo == f"Bearer {REDACTED}" + assert member.__cause__.args == (f"under the member {REDACTED}",) + # A traceback shows every member of a group, and what is chained under each. + shown = "".join(traceback.format_exception(outer)) + assert [key for key in SENTINEL_SPELLINGS if key in shown] == [] + + +def test_the_exception_the_application_was_handling_does_not_fail_the_scrub( + httpserver: HTTPServer, +) -> None: + Permit(make_config(httpserver)) + handled = AppStringHeadersError() + try: + raise_(handled) + except AppStringHeadersError: + outer = aiohttp_double.raised(aiohttp.ClientError(f"outer {SENTINEL}")) + assert outer.__context__ is handled + before = (repr(vars(handled)), repr(handled.args)) + + assert scrub_request_info(outer, handled=handled) + + assert outer.args == (f"outer {REDACTED}",) + assert (repr(vars(handled)), repr(handled.args)) == before + + +def test_the_exception_the_application_was_handling_under_one_left_as_it_is_is_not_checked( + httpserver: HTTPServer, +) -> None: + Permit(make_config(httpserver)) + handled = AppStringHeadersError() + try: + raise_(handled) + except AppStringHeadersError: + # Raised outside the request's packages, as an event loop of another package does. + left = aiohttp_double.calling(lambda: raise_(ConnectionRefusedError("refused"))) + assert left.__context__ is handled + outer = aiohttp_double.raised(aiohttp.ClientError("outer")) + outer.__cause__ = left + + assert scrub_request_info(outer, handled=handled) + + +def test_the_exception_the_application_was_handling_is_left_alone_whatever_its_frames( + httpserver: HTTPServer, +) -> None: + Permit(make_config(httpserver)) + error = aiohttp_double.context_only(SENTINEL) + handled = error.__context__ + + assert scrub_request_info(error, handled=handled) + + assert handled.args == (f"inner {SENTINEL}",) + + +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_a_content_type_error_that_cannot_be_scrubbed_is_not_chained( + httpserver: HTTPServer, client_class: type[Permit], monkeypatch: pytest.MonkeyPatch +) -> None: + 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(f"{USERS}/user-1", method="GET").respond_with_data( + "bad gateway", status=502, content_type="text/html" + ) + permit = client_class(make_config(httpserver)) + monkeypatch.setattr( + "permit.exceptions.scrub_request_info", + lambda holder, **_: not isinstance(holder, aiohttp.ContentTypeError), + ) + + with pytest.raises(PermitApiError) as caught: + await resolved(permit.api.users.get("user-1")) + + assert caught.value.__cause__ is None + assert not any( + isinstance(chained, aiohttp.ContentTypeError) + for chained in chained_exceptions(caught.value) + ) + + +@pytest.mark.parametrize("client_class", CLIENT_CLASSES) +async def test_an_exception_the_application_is_handling_leaves_a_content_type_error_chained( + httpserver: HTTPServer, client_class: type[Permit] +) -> None: + 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(f"{USERS}/user-1", method="GET").respond_with_data( + "bad gateway", status=502, content_type="text/html" + ) + permit = client_class(make_config(httpserver)) + handled = AppStringHeadersError() + + try: + raise_(handled) + except AppStringHeadersError: + with pytest.raises(PermitApiError) as caught: + await resolved(permit.api.users.get("user-1")) + + # The application's exception holds the key, but it is the application's. + assert isinstance(caught.value.__cause__, aiohttp.ContentTypeError) + + +def test_the_error_the_sdk_caught_is_scrubbed_whatever_its_frames(httpserver: HTTPServer) -> None: + Permit(make_config(httpserver)) + # Its traceback has a frame of this module's, which isn't one the request runs through. + caught: aiohttp.ClientError = aiohttp_double.calling( + lambda: raise_(aiohttp.ClientError(f"caught {SENTINEL}")) + ) + + error = PermitConnectionError("the request failed", error=caught) + + assert caught.args == (f"caught {REDACTED}",) + assert error.original_error is caught diff --git a/uv.lock b/uv.lock index 5c853a53..d33995c7 100644 --- a/uv.lock +++ b/uv.lock @@ -1012,6 +1012,7 @@ source = { editable = "." } dependencies = [ { name = "aiohttp" }, { name = "loguru" }, + { name = "multidict" }, { name = "pydantic", version = "1.10.26", source = { registry = "https://pypi.org/simple" }, extra = ["email"], marker = "extra == 'group-6-permit-pydantic-v1'" }, { name = "pydantic", version = "2.13.5", source = { registry = "https://pypi.org/simple" }, extra = ["email"], marker = "extra == 'group-6-permit-pydantic-v2' or extra != 'group-6-permit-pydantic-v1'" }, { name = "typing-extensions" }, @@ -1042,6 +1043,7 @@ pydantic-v2 = [ requires-dist = [ { name = "aiohttp", specifier = ">=3.14.3,<4" }, { name = "loguru", specifier = ">=0.7.3,<1" }, + { name = "multidict", specifier = ">=4.5,<7" }, { name = "pydantic", extras = ["email"], marker = "python_full_version < '3.13'", specifier = ">=1.10.18,!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.*,!=2.4.0,!=2.4.1" }, { name = "pydantic", extras = ["email"], marker = "python_full_version == '3.13.*'", specifier = ">=1.10.18,!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.*,!=2.4.*,!=2.5.*,!=2.6.*,!=2.7.*" }, { name = "pydantic", extras = ["email"], marker = "python_full_version >= '3.14'", specifier = ">=1.10.25,!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.*,!=2.4.*,!=2.5.*,!=2.6.*,!=2.7.*,!=2.8.*,!=2.9.*,!=2.10.*,!=2.11.*,!=2.12.*" },