From a7f0a49dcf77f52a81e8621d6802313c8d358b9b Mon Sep 17 00:00:00 2001 From: Ahmed Allam Date: Wed, 23 Sep 2026 02:17:56 +0000 Subject: [PATCH] refactor(llm): drop secret redaction from the request log Response headers and error text are stored as the provider sent them; the only thing still left out by name is the caller's own credential in the request parameters (api_key / authorization / extra_headers). --- strix/llm/request_log.py | 119 +++++++--------------------------- tests/test_llm_request_log.py | 87 +++++++------------------ 2 files changed, 47 insertions(+), 159 deletions(-) diff --git a/strix/llm/request_log.py b/strix/llm/request_log.py index cad9e8f8..11e37f0a 100644 --- a/strix/llm/request_log.py +++ b/strix/llm/request_log.py @@ -1,4 +1,4 @@ -"""Structured, secret-free record of every model provider call. +"""Structured record of every model provider call. One :class:`LlmRequestEvent` per HTTP attempt against a provider, whatever the route (LiteLLM or the native OpenAI client) and whatever the outcome. Retries @@ -9,12 +9,12 @@ provider's support team asks for when a call was blocked or misbehaved. The typed fields are the common ground every provider shares (status, ids, timing, sizes, tokens, cost). Everything else a provider or SDK reports about -the attempt travels free-form: the response headers minus credential-bearing -names, and a ``details`` object with the request parameters, the full usage -object, the SDK's hidden parameters and the error body. Content (prompts, -completions, tool arguments) and credentials are removed from both, values are -redacted and every string, list and object is bounded. Raw request and -response bodies are never captured. +the attempt travels free-form: the response headers, and a ``details`` object +with the request parameters, the full usage object, the SDK's hidden +parameters and the error body. Content (prompts, completions, tool arguments) +and the caller's own credentials are left out of both by key name, and every +string, list and object is bounded. Raw request and response bodies are never +captured. Sinks are plain callables. The built-in sink writes one log line per event; deployments register their own (a database, a queue) with @@ -110,11 +110,10 @@ class LlmRequestEvent: # Streamed calls only. time_to_first_token_ms: int | None = None finish_reason: str | None = None - # Every response header the provider sent, name-normalized, minus - # credential-bearing names; values redacted and capped. + # Every response header the provider sent, name-normalized, values capped. response_headers: dict[str, str] | None = None # Free-form: request parameters, full usage object, SDK hidden params, - # error body ... with content and credentials removed and sizes bounded. + # error body ... with content removed and sizes bounded. details: dict[str, Any] | None = None def to_dict(self) -> dict[str, Any]: @@ -213,41 +212,8 @@ def emit(event: LlmRequestEvent) -> None: logger.exception("LLM request log sink %r failed", sink) -# --------------------------------------------------------------------------- # -# Redaction # -# --------------------------------------------------------------------------- # - -# Credential shapes a provider or gateway error may echo back. Broad by design: -# a redacted-but-useless message costs nothing, a leaked key costs a rotation. -_SECRET_PATTERNS: tuple[re.Pattern[str], ...] = ( - re.compile(r"(?i)\b(?:bearer|basic)\s+[a-z0-9._~+/=-]{8,}"), - re.compile(r"\bsk-(?:ant-|proj-|or-v1-)?[A-Za-z0-9_-]{8,}"), - re.compile(r"\b(?:AKIA|ASIA)[A-Z0-9]{16}\b"), - re.compile(r"\bAIza[0-9A-Za-z_-]{20,}\b"), - re.compile(r"\bgh[pousr]_[A-Za-z0-9]{20,}\b"), - re.compile(r"\bxox[abprs]-[A-Za-z0-9-]{10,}\b"), - re.compile(r"\bey[A-Za-z0-9_-]{10,}\.[A-Za-z0-9_-]{10,}\.[A-Za-z0-9_-]{10,}\b"), - re.compile( - r"(?i)([\"']?(?:api[_-]?key|x-api-key|authorization|api[_-]?token|secret|password)" - r"[\"']?\s*[:=]\s*[\"']?)(?:(?:bearer|basic)\s+)?[^\s\"',;&]{4,}" - ), - re.compile(r"(?i)((?:api[_-]?key|token|secret|password)=)[^&\s\"']{4,}"), -) - - -def redact(text: str) -> str: - """Replace anything credential-shaped in ``text``.""" - for pattern in _SECRET_PATTERNS: - if pattern.groups: - text = pattern.sub(lambda m: f"{m.group(1)}[REDACTED]", text) - else: - text = pattern.sub("[REDACTED]", text) - return text - - def clean_error_message(exc: BaseException) -> str: message = str(exc).strip() or type(exc).__name__ - message = redact(message) if len(message) > ERROR_MESSAGE_MAX_CHARS: message = message[: ERROR_MESSAGE_MAX_CHARS - 1] + "…" return message @@ -324,20 +290,6 @@ def request_id_from_reply(headers: Mapping[str, Any] | None, text: str | None = FINISH_REASON_MAX_CHARS = 128 -# Response headers are kept whole, except names that carry a credential. The -# list is a deny-list on purpose: a provider's new telemetry header should show -# up without a code change, a leaked credential must not. -_DENIED_HEADER_FRAGMENTS: tuple[str, ...] = ( - "auth", # authorization, proxy-authorization, www-authenticate, x-auth-token - "cookie", - "api-key", - "apikey", - "secret", - "password", - "credential", - "signature", - "session", -) HEADERS_MAX_COUNT = 64 HEADER_VALUE_MAX_CHARS = 512 @@ -375,21 +327,10 @@ _CONTENT_KEYS: frozenset[str] = frozenset( "original_response", } ) -# Keys whose value is or may hold a credential, whatever the provider calls it. -_SECRET_KEY_FRAGMENTS: tuple[str, ...] = ( - "api_key", - "api-key", - "apikey", - "authorization", - "secret", - "password", - "credential", - "cookie", - "headers", # request header blocks carry the auth header - "access_token", - "refresh_token", - "id_token", - "bearer", +# Request parameters that hold the caller's own credential: the key itself and +# the header block (``extra_headers``) the authorization header travels in. +_CREDENTIAL_KEYS: frozenset[str] = frozenset( + {"api_key", "authorization", "extra_headers", "headers"} ) DETAILS_MAX_BYTES = 16 * 1024 DETAILS_MAX_DEPTH = 6 @@ -402,7 +343,7 @@ def _normalize_header_name(key: object) -> str: def headers_from_response(headers: Mapping[str, Any] | None) -> dict[str, str] | None: - """The provider's response headers, minus credential-bearing names, redacted and capped.""" + """The provider's response headers, name-normalized and value-capped.""" if not headers: return None picked: dict[str, str] = {} @@ -413,30 +354,19 @@ def headers_from_response(headers: Mapping[str, Any] | None) -> dict[str, str] | if not text: continue name = _normalize_header_name(key) - if not name or any(fragment in name for fragment in _DENIED_HEADER_FRAGMENTS): + if not name: continue - picked.setdefault(name, redact(text)[:HEADER_VALUE_MAX_CHARS]) + picked.setdefault(name, text[:HEADER_VALUE_MAX_CHARS]) if len(picked) >= HEADERS_MAX_COUNT: break return picked or None -def _strip_url_secrets(text: str) -> str: - """Drop the query and fragment of anything URL-shaped; gateways key on them.""" - if "://" not in text: - return text - try: - parts = urlsplit(text) - except ValueError: - return text - return parts._replace(query="", fragment="").geturl() - - def _sanitize_value(value: object, depth: int) -> object: # noqa: PLR0911 if value is None or isinstance(value, bool | int | float): return value if isinstance(value, str): - return redact(_strip_url_secrets(value))[:DETAILS_MAX_STRING] + return value[:DETAILS_MAX_STRING] if isinstance(value, datetime | date): return value.isoformat() if depth >= DETAILS_MAX_DEPTH: @@ -450,7 +380,7 @@ def _sanitize_value(value: object, depth: int) -> object: # noqa: PLR0911 for raw_key, item in cast("Mapping[object, object]", value).items(): key = str(raw_key) lowered = key.lower() - if lowered in _CONTENT_KEYS or any(f in lowered for f in _SECRET_KEY_FRAGMENTS): + if lowered in _CONTENT_KEYS or lowered in _CREDENTIAL_KEYS: continue cleaned = _sanitize_value(item, depth + 1) if cleaned is None or cleaned in ({}, []): @@ -462,14 +392,14 @@ def _sanitize_value(value: object, depth: int) -> object: # noqa: PLR0911 if isinstance(value, Sequence | set | frozenset): items = list(cast("Sequence[object]", value))[:DETAILS_MAX_ITEMS] return [_sanitize_value(item, depth + 1) for item in items] - return redact(str(value))[:DETAILS_MAX_STRING] + return str(value)[:DETAILS_MAX_STRING] def sanitize_details(value: object) -> dict[str, Any] | None: - """A bounded, content-free, credential-free copy of ``value`` (a mapping), or None. + """A bounded, content-free copy of ``value`` (a mapping), or None. - Content keys and secret-shaped keys are dropped by name, strings are - redacted and capped, nesting, item counts and total size are bounded. When + Content keys and the caller's credential keys are dropped by name, strings + are capped, nesting, item counts and total size are bounded. When the copy is still too large the biggest top-level entries go first and their names are listed under ``_dropped``. """ @@ -928,7 +858,7 @@ def _litellm_failure( error_type = error_type or _str_or_none(error_info.get("error_class")) or "Exception" if error_message is None: raw = _str_or_none(error_info.get("error_message")) or _str_or_none(slo.get("error_str")) - error_message = redact(raw)[:ERROR_MESSAGE_MAX_CHARS] if raw else error_type + error_message = raw[:ERROR_MESSAGE_MAX_CHARS] if raw else error_type provider = _str_or_none(error_info.get("llm_provider")) if provider: error.setdefault("llm_provider", provider) @@ -1498,7 +1428,7 @@ def failure_text(exc: BaseException) -> str: ``request_id``) but drops the ``request-id`` header; OpenAI errors carry only the header. Either way the id lands in the text an operator reads. """ - text = redact(str(exc)) or type(exc).__name__ + text = str(exc) or type(exc).__name__ request_id: str | None = None if isinstance(exc, APIError): _, request_id = _openai_error_fields(exc) @@ -1527,7 +1457,6 @@ __all__ = [ "json_size", "json_text", "merge_details", - "redact", "register_sink", "request_id_from_headers", "request_id_from_reply", diff --git a/tests/test_llm_request_log.py b/tests/test_llm_request_log.py index 5e5ed504..85d03b03 100644 --- a/tests/test_llm_request_log.py +++ b/tests/test_llm_request_log.py @@ -158,44 +158,16 @@ def test_api_host_never_leaks_path_or_query() -> None: # --------------------------------------------------------------------------- # -# redaction # +# error message # # --------------------------------------------------------------------------- # -@pytest.mark.parametrize( - "secret", - [ - "sk-ant-api03-abcdefghijklmnopqrstuvwxyz0123456789", - "sk-proj-abcdefghijklmnopqrstuvwxyz", - "Bearer abcdefghijklmnopqrstuvwxyz0123456789", - "AKIAABCDEFGHIJKLMNOP", - "AIzaSyABCDEFGHIJKLMNOPQRSTUVWXYZ01234", - "ghp_abcdefghijklmnopqrstuvwxyz0123456789", - "xoxb-1234567890-abcdefghij", - "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIxMjM0NTY3ODkwIn0.abcdefghijklmnopqrstuvwxyz", - ], -) -def test_redact_removes_credential_shapes(secret: str) -> None: - redacted = request_log.redact(f"upstream said: {secret} (401)") - assert secret not in redacted - assert "[REDACTED]" in redacted - assert "(401)" in redacted - - -def test_redact_key_value_forms_keep_the_key_name() -> None: - text = 'invalid "api_key": "abcd1234", authorization: Basic Zm9vOmJhcg== token=abcdef99' - redacted = request_log.redact(text) - assert "abcd1234" not in redacted - assert "Zm9vOmJhcg==" not in redacted - assert "abcdef99" not in redacted - assert '"api_key": "[REDACTED]"' in redacted - - -def test_clean_error_message_truncates_and_redacts() -> None: - exc = RuntimeError("x" * 5000 + " sk-ant-api03-abcdefghijklmnop") +def test_clean_error_message_truncates_and_keeps_the_text() -> None: + exc = RuntimeError("x" * 5000) message = request_log.clean_error_message(exc) assert len(message) <= request_log.ERROR_MESSAGE_MAX_CHARS - assert "sk-ant" not in message + assert message.endswith("…") + assert request_log.clean_error_message(RuntimeError("upstream 401")) == "upstream 401" assert request_log.clean_error_message(RuntimeError("")) == "RuntimeError" @@ -313,14 +285,13 @@ def test_litellm_timeout_is_an_error_event_with_no_status() -> None: assert event.provider_request_id is None -def test_litellm_failure_message_is_redacted() -> None: - exc = _anthropic_error(401, "invalid x-api-key: sk-ant-api03-abcdefghijklmnopqrstu") +def test_litellm_failure_message_is_the_providers_text() -> None: + exc = _anthropic_error(401, "invalid x-api-key") event = request_log.event_from_litellm( _anthropic_kwargs(exc), None, None, None, outcome="error" ) assert event.error_message is not None - assert "sk-ant-api03" not in event.error_message - assert "[REDACTED]" in event.error_message + assert "invalid x-api-key" in event.error_message def test_litellm_streaming_flag_and_call_id() -> None: @@ -431,7 +402,7 @@ def test_log_line_sink_formats_without_content(caplog: pytest.LogCaptureFixture) # --------------------------------------------------------------------------- # -def test_response_headers_keep_everything_but_credentials() -> None: +def test_response_headers_keep_everything_as_sent() -> None: picked = request_log.headers_from_response( { "llm_provider-anthropic-ratelimit-requests-remaining": "49", @@ -443,17 +414,9 @@ def test_response_headers_keep_everything_but_credentials() -> None: "cf-ray": "8f0-FRA", "x-should-retry": "false", "openai-processing-ms": "812", - "x-vendor-new-header": "kept without a code change", - "authorization": "Bearer sk-ant-secret", - "Proxy-Authorization": "Basic abc", "WWW-Authenticate": "Bearer realm=x", - "x-api-key": "sk-ant-secret", - "api-key": "azure-secret", - "set-cookie": "session=abc", - "x-session-token": "abc", - "x-amz-signature": "sig", - "x-goog-api-key": "AIzaSyA-secret-key-value-1234567890", - "x-leaky": "token sk-ant-api03-abcdefghijklmnopqrstu inside", + "set-cookie": "__cf_bm=abc", + "x-vendor-new-header": "kept without a code change", "x-empty": " ", "x-object": {"not": "a string"}, } @@ -468,10 +431,10 @@ def test_response_headers_keep_everything_but_credentials() -> None: "cf-ray": "8f0-FRA", "x-should-retry": "false", "openai-processing-ms": "812", + "www-authenticate": "Bearer realm=x", + "set-cookie": "__cf_bm=abc", "x-vendor-new-header": "kept without a code change", - "x-leaky": "token [REDACTED] inside", } - assert "secret" not in str(picked) assert request_log.headers_from_response({}) is None assert request_log.headers_from_response(None) is None @@ -484,7 +447,7 @@ def test_response_headers_are_bounded() -> None: assert all(len(v) <= request_log.HEADER_VALUE_MAX_CHARS for v in picked.values()) -def test_details_drop_content_and_credentials_keep_metadata() -> None: +def test_details_drop_content_and_the_callers_key_keep_metadata() -> None: details = request_log.sanitize_details( { "max_tokens": 4096, @@ -494,13 +457,13 @@ def test_details_drop_content_and_credentials_keep_metadata() -> None: "tools": [{"name": "t", "input_schema": {}}], "api_key": "sk-ant-secret", "extra_headers": {"authorization": "Bearer x"}, - "api_base": "https://gw.example/v1?token=abc#frag", + "api_base": "https://gw.example/v1?tenant=abc", "usage": { "input_tokens": 10, "cache_creation_input_tokens": 3, "server_tool_use": {"web_search_requests": 1}, }, - "note": "leaked sk-ant-api03-abcdefghijklmnopqrstu here", + "note": "kept as written", "when": datetime(2026, 9, 19, tzinfo=UTC), "nested": {"a": {"b": {"c": {"d": {"e": {"f": {"g": 1}}}}}}}, "empty": {}, @@ -511,13 +474,13 @@ def test_details_drop_content_and_credentials_keep_metadata() -> None: "max_tokens": 4096, "temperature": 0, "thinking": {"type": "enabled", "budget_tokens": 1024}, - "api_base": "https://gw.example/v1", + "api_base": "https://gw.example/v1?tenant=abc", "usage": { "input_tokens": 10, "cache_creation_input_tokens": 3, "server_tool_use": {"web_search_requests": 1}, }, - "note": "leaked [REDACTED] here", + "note": "kept as written", "when": "2026-09-19T00:00:00+00:00", "nested": {"a": {"b": {"c": {"d": {"e": "…"}}}}}, } @@ -565,7 +528,6 @@ def test_litellm_success_carries_sizes_finish_reason_headers_and_details() -> No "anthropic-ratelimit-requests-remaining": "49", "anthropic-ratelimit-tokens-remaining": "39000", "anthropic-organization-id": "org-123", - "x-api-key": "sk-ant-secret", }, ) kwargs["optional_params"] = { @@ -697,7 +659,6 @@ def test_litellm_failure_carries_status_body_size_headers_and_error_details() -> "retry-after": "7", "anthropic-ratelimit-requests-remaining": "0", "content-type": "application/json", - "x-api-key": "sk-ant-secret", }, ) kwargs = _anthropic_kwargs(exc) @@ -1073,7 +1034,7 @@ async def test_openai_route_success_reads_request_id_and_headers_from_the_wire( "x-request-id": "req_wire_ok", "openai-processing-ms": "812", "x-ratelimit-remaining-tokens": "999", - "Set-Cookie": "session=abc", + "Set-Cookie": "__cf_bm=abc", }, ) model = request_log.RequestLoggingModel( @@ -1092,7 +1053,7 @@ async def test_openai_route_success_reads_request_id_and_headers_from_the_wire( assert event.response_headers is not None assert event.response_headers["openai-processing-ms"] == "812" assert event.response_headers["x-ratelimit-remaining-tokens"] == "999" - assert "set-cookie" not in event.response_headers + assert event.response_headers["set-cookie"] == "__cf_bm=abc" @pytest.mark.asyncio @@ -1487,12 +1448,10 @@ def test_failure_text_does_not_duplicate_body_id() -> None: assert "[provider request id" not in text -def test_failure_text_uses_litellm_exception_headers_and_redacts() -> None: - exc = _anthropic_error( - 401, "bad key sk-ant-api03-abcdefghijklmnopqrstu", {"request-id": "req_exc_hdr"} - ) +def test_failure_text_uses_litellm_exception_headers() -> None: + exc = _anthropic_error(401, "bad key", {"request-id": "req_exc_hdr"}) text = request_log.failure_text(exc) - assert "sk-ant-api03" not in text + assert "bad key" in text assert text.endswith("[provider request id: req_exc_hdr]")