mirror of
https://github.com/usestrix/strix.git
synced 2026-10-13 03:57:59 +00:00
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).
This commit is contained in:
parent
13c66cbb9e
commit
a7f0a49dcf
2 changed files with 47 additions and 159 deletions
|
|
@ -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",
|
||||
|
|
|
|||
|
|
@ -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]")
|
||||
|
||||
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue