From 690890398a47cf7dd690a60c257a624e0c1d697b Mon Sep 17 00:00:00 2001 From: yucheng Date: Fri, 30 Oct 2026 18:39:18 -0700 Subject: [PATCH 1/9] feat(logging): add helpers that scrub a request's own text out of failure error text --- litellm/litellm_core_utils/redact_messages.py | 239 +++++++++++++++++- .../test_redact_messages.py | 204 ++++++++++++++- 2 files changed, 438 insertions(+), 5 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index ac5c0720eff..4491982d4c9 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -10,11 +10,14 @@ import asyncio import copy import inspect -from collections.abc import Iterable, Mapping, Sequence +import itertools +import json +import re +from collections.abc import Collection, Iterable, Mapping, Sequence from dataclasses import replace from typing import TYPE_CHECKING, Any, Final -from pydantic import JsonValue, TypeAdapter, ValidationError +from pydantic import BaseModel, JsonValue, TypeAdapter, ValidationError import litellm from litellm.constants import REDACTED_BY_LITELLM @@ -23,6 +26,9 @@ from litellm.litellm_core_utils.classifier_logging import without_classifier_aud from litellm.litellm_core_utils.core_helpers import ( get_metadata_variable_name_from_kwargs, ) +from litellm.litellm_core_utils.initialize_dynamic_callback_params import ( + initialize_standard_callback_dynamic_params, +) from litellm.litellm_core_utils.served_output_texts import SERVED_OUTPUT_TEXTS_KEY from litellm.llms.base_llm.guardrail_translation.utils import stream_item_field, stream_item_items from litellm.llms.vertex_ai.common_utils import ( @@ -31,7 +37,7 @@ from litellm.llms.vertex_ai.common_utils import ( ) from litellm.secret_managers.main import str_to_bool from litellm.types.router import BaselineRouteStamp -from litellm.types.utils import StandardCallbackDynamicParams +from litellm.types.utils import StandardCallbackDynamicParams, StandardLoggingPayloadErrorInformation if TYPE_CHECKING: from litellm.litellm_core_utils.litellm_logging import ( @@ -239,6 +245,10 @@ def _as_mapping(value: object) -> Mapping[str, object] | None: return value if isinstance(value, Mapping) else None # pyright: ignore[reportUnknownVariableType] # keys are read one by one +def _as_items(value: object) -> tuple[object, ...] | None: + return tuple(value) if isinstance(value, (list, tuple)) else None # pyright: ignore[reportUnknownVariableType, reportUnknownArgumentType] # items are walked one by one + + def _redact_provider_specific_fields(message: object) -> None: if (fields := _as_mapping(getattr(message, "provider_specific_fields", None))) is not None: setattr(message, "provider_specific_fields", _redacted_provider_specific_fields(fields)) # noqa: B010 # typed as object @@ -413,6 +423,187 @@ def _redacted_responses_api_response( return _with_redacted_instructions(redacted) if redact_instructions else redacted +_REQUEST_TEXT_KEYS: Final = ("messages", "input", "prompt", "system", "instructions") +_STRUCTURAL_KEYS: Final = frozenset({"role", "type", "id", "tool_call_id", "name"}) +_MIN_UNQUOTED_TEXT_LENGTH: Final = 4 +_ESCAPED_CHARACTERS: Final = ('"', "\\") +# pydantic shows a long input value as its repr's first 25 and last 24 characters around "...", quotes and +# container keys included, so each side of the cut shows at most 24 characters of a quoted text +_CUT_SIDE_LENGTH: Final = 24 +_CUT_ECHO_HEAD: Final = re.compile(rf"(?<=['\"])[^'\"]{{1,{_CUT_SIDE_LENGTH}}}(?=\.\.\.)") +_CUT_ECHO_TAIL: Final = re.compile(rf"(?<=\.\.\.)[^'\"]{{1,{_CUT_SIDE_LENGTH}}}(?=['\"])") +_MAX_SCRUB_COMPARISONS: Final = 10_000_000 + + +def _child_values(value: object) -> tuple[object, ...]: + if (mapping := _as_mapping(value)) is not None: + return tuple(item for key, item in mapping.items() if key not in _STRUCTURAL_KEYS) + if (items := _as_items(value)) is not None: + return items + if isinstance(value, BaseModel): + return (value.model_dump(),) + return () + + +def _next_level(level: tuple[object, ...], _: None) -> tuple[object, ...]: + return tuple(itertools.chain.from_iterable(map(_child_values, level))) + + +def request_texts(*values: object) -> frozenset[str]: + """ + The non-empty strings a request carries under ``values``, skipping structural fields such as ``role`` + and ``type``. A value passed more than once is walked once. + """ + distinct_values: Final = tuple({id(value): value for value in values}.values()) + levels: Final = itertools.takewhile( + bool, itertools.accumulate(itertools.repeat(None), _next_level, initial=distinct_values) + ) + return frozenset(value for value in itertools.chain.from_iterable(levels) if isinstance(value, str) and value) + + +def failure_request_texts(model_call_details: Mapping[str, object], *originals: object) -> frozenset[str]: + """The request text a failure on this call can quote: its messages, input, prompt, system prompt and instructions.""" + optional_params: Final = _as_mapping(model_call_details.get("optional_params")) or {} + return request_texts( + *originals, + *(model_call_details.get(key) for key in _REQUEST_TEXT_KEYS), + *(optional_params.get(key) for key in ("system", "instructions")), + ) + + +def _echo_forms(text: str) -> frozenset[str]: + """How an error can quote ``text``: verbatim, or JSON or repr escaped. Printable ASCII without a double quote + or a backslash escapes to itself.""" + if text.isascii() and text.isprintable() and not any(character in text for character in _ESCAPED_CHARACTERS): + return frozenset((text,)) + return frozenset({text, json.dumps(text)[1:-1], json.dumps(text, ensure_ascii=False)[1:-1], repr(text)[1:-1]}) + + +def _cut_sides(text: str) -> str: + """ + The start and end of ``text`` that a pydantic cut can show, for a text too long to be quoted whole, with + ``text``'s quote characters between them so repr escapes the sides as it escapes the whole ``text``. + """ + quotes: Final = "".join(quote for quote in "'\"" if quote in text) + return f"{text[:_CUT_SIDE_LENGTH]}{quotes}{text[-_CUT_SIDE_LENGTH:]}" + + +def _cut_echoes(text: str, forms: Collection[str]) -> tuple[tuple[str, str], ...]: + """ + Each side of a quoted value ``text`` cuts short with ``...`` that starts or ends one of ``forms``, as + pydantic shows a long input value, with its pattern anchored to the quote and the cut. + """ + heads: Final = frozenset(match.group() for match in _CUT_ECHO_HEAD.finditer(text)) + tails: Final = frozenset(match.group() for match in _CUT_ECHO_TAIL.finditer(text)) + return ( + *( + (head, f"(?<=['\"]){re.escape(head)}(?=\\.\\.\\.)") + for head in heads + if any(form.startswith(head) for form in forms) + ), + *( + (tail, f"(?<=\\.\\.\\.){re.escape(tail)}(?=['\"])") + for tail in tails + if any(form.endswith(tail) for form in forms) + ), + ) + + +def scrub_request_text(text: str, texts: Collection[str]) -> str: + """ + ``text`` with every quote of the request's own ``texts`` replaced by ``REDACTED_BY_LITELLM``, so an + error that does not echo the prompt keeps its wording. A search too large for a failure path + replaces the whole text. + """ + if not text or not texts: + return text + if len(text) * len(texts) > _MAX_SCRUB_COMPARISONS: + return REDACTED_BY_LITELLM + forms: Final = frozenset( + itertools.chain.from_iterable(_echo_forms(each) for each in texts if len(each) <= len(text)) + ) + cut_forms: Final = frozenset( + itertools.chain.from_iterable(_echo_forms(_cut_sides(each)) for each in texts if len(each) > len(text)) + ) + echoes: Final = sorted( + (*((form, _echo_pattern(form)) for form in forms if form in text), *_cut_echoes(text, forms | cut_forms)), + key=lambda echo: len(echo[0]), + reverse=True, + ) + if not echoes: + return text + return re.sub("|".join(pattern for _, pattern in echoes), REDACTED_BY_LITELLM, text) + + +def _echo_pattern(form: str) -> str: + """A quote of ``form``. A form short enough to occur in ordinary wording only counts between quotes.""" + escaped: Final = re.escape(form) + return escaped if len(form) >= _MIN_UNQUOTED_TEXT_LENGTH else f"(?<=['\"]){escaped}(?=['\"])" + + +def scrubbed_error_information( + error_information: StandardLoggingPayloadErrorInformation, texts: Collection[str] +) -> StandardLoggingPayloadErrorInformation: + """``error_information`` with the request's ``texts`` scrubbed out of its message and traceback. The type, + status code and every other field carry no prompt and are left as they are.""" + error_message: Final = error_information.get("error_message") + traceback_text: Final = error_information.get("traceback") + return { + **error_information, + "error_message": error_message if error_message is None else scrub_request_text(error_message, texts), + "traceback": traceback_text if traceback_text is None else scrub_request_text(traceback_text, texts), + } + + +def _with_scrubbed_text( + mapping: Mapping[str, object], fields: tuple[str, ...], texts: Collection[str] +) -> Mapping[str, object]: + return { + key: scrub_request_text(value, texts) if key in fields and isinstance(value, str) else value + for key, value in mapping.items() + } + + +def scrubbed_error_fields(payload: Mapping[str, object], texts: Collection[str]) -> Mapping[str, object]: + """The ``error_str`` and ``error_information`` entries of a ``StandardLoggingPayload`` with the request's + ``texts`` scrubbed out, to merge over a copy of the payload. Absent entries are left out.""" + error_str: Final = payload.get("error_str") + error_information: Final = _as_mapping(payload.get("error_information")) + return { + **({"error_str": scrub_request_text(error_str, texts)} if isinstance(error_str, str) else {}), + **( + {"error_information": _with_scrubbed_text(error_information, ("error_message", "traceback"), texts)} + if error_information is not None + else {} + ), + } + + +def scrubbed_exception_text(model_call_details: Mapping[str, object]) -> tuple[str, str] | None: + """ + The error message and traceback a failure logged when redaction scrubbed the request's text out of + either, for callbacks that would otherwise record the raw exception. ``None`` when nothing was scrubbed. + Without a logged error message, the message is the exception text that ends the traceback. + """ + payload: Final = _as_mapping(model_call_details.get("standard_logging_object")) or {} + error_information: Final = _as_mapping(payload.get("error_information")) or {} + message: Final = error_information.get("error_message") + logged_traceback: Final = model_call_details.get("traceback_exception") + traceback_text: Final = ( + logged_traceback if isinstance(logged_traceback, str) else error_information.get("traceback") + ) + if not any(isinstance(text, str) and REDACTED_BY_LITELLM in text for text in (message, traceback_text)): + return None + logged_traceback_text: Final = traceback_text if isinstance(traceback_text, str) else "" + return (message if isinstance(message, str) else _exception_text(logged_traceback_text), logged_traceback_text) + + +def _exception_text(traceback_text: str) -> str: + """The lines after the last indented frame line of ``traceback_text``.""" + lines: Final = reversed(traceback_text.rstrip().splitlines()) + return "\n".join(reversed(tuple(itertools.takewhile(lambda line: not line.startswith(" "), lines)))) + + def redacted_standard_logging_payload(payload: Mapping[str, object]) -> Mapping[str, object]: """ Return a copy of a ``StandardLoggingPayload`` with its messages and response redacted. @@ -688,6 +879,48 @@ def should_redact_message_logging(model_call_details: dict) -> bool: return litellm.turn_off_message_logging is True +def should_redact_failure_logging(model_call_details: Mapping[str, object]) -> bool: + """ + ``should_redact_message_logging`` for the failure path, which must log the failure whatever the + request carried. Headers that are not a mapping carry no redaction header, so the request's own + setting or the global one decides. + """ + try: + return should_redact_message_logging(dict(model_call_details)) + except AttributeError: + dynamic_turn_off: Final = _get_turn_off_message_logging_from_dynamic_params(dict(model_call_details)) + return dynamic_turn_off if dynamic_turn_off is not None else litellm.turn_off_message_logging is True + + +def should_redact_failed_request(request_data: Mapping[str, object]) -> bool: + """ + The redaction decision for proxy failure hooks, which get the request body but not its logging + object: the same metadata, headers and dynamic params the logging object would read. When the + logging object would reject the request's callback params, the global setting decides. + """ + body: Final = dict(request_data) + try: + dynamic_params: Final = initialize_standard_callback_dynamic_params(body) + except ValueError: + return litellm.turn_off_message_logging is True + return should_redact_failure_logging( + { + "litellm_params": {key: body[key] for key in ("metadata", "litellm_metadata") if key in body}, + "standard_callback_dynamic_params": dynamic_params, + } + ) + + +def scrubbed_error_information_for_request( + error_information: StandardLoggingPayloadErrorInformation, request_data: Mapping[str, object] +) -> StandardLoggingPayloadErrorInformation: + """``error_information`` built from a proxy failure hook's exception, with the request's own text + scrubbed out when the request's message logging is redacted.""" + if not should_redact_failed_request(request_data): + return error_information + return scrubbed_error_information(error_information, failure_request_texts(request_data)) + + def redact_message_input_output_from_logging(model_call_details: dict, result, input: object | None = None) -> Any: """ Removes messages, prompts, input, response from logging. This modifies the data in-place diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index 491ea5315ff..71a76e5eaf2 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -11,7 +11,8 @@ import importlib import json import os import threading -from collections.abc import AsyncIterator, Mapping +import tracemalloc +from collections.abc import AsyncIterator, Callable, Mapping from datetime import datetime from types import MappingProxyType, SimpleNamespace from typing import Final, Optional, Union @@ -20,7 +21,7 @@ from unittest.mock import patch import httpx import pytest import pytest_asyncio -from pydantic import JsonValue +from pydantic import JsonValue, TypeAdapter, ValidationError import litellm from litellm.constants import LOGGING_WORKER_MAX_TIME_PER_COROUTINE @@ -33,6 +34,11 @@ from litellm.litellm_core_utils.redact_messages import ( redacted_model_call_details_for_custom_logger, redacted_response_obj_for_custom_logger, redacted_standard_logging_payload, + request_texts, + scrub_request_text, + scrubbed_error_information_for_request, + scrubbed_exception_text, + should_redact_failed_request, should_redact_message_logging, ) from litellm.llms.custom_httpx.http_handler import AsyncHTTPHandler, HTTPHandler @@ -43,6 +49,7 @@ from litellm.types.utils import ( ModelResponseStream, ResponsesAPIResponse, StandardLoggingPayload, + StandardLoggingPayloadErrorInformation, TextCompletionResponse, ) from tests._vcr_conftest_common import install_live_call_probe, record_vcr_outcome @@ -2220,3 +2227,196 @@ def test_perform_redaction_strips_the_matched_text_from_the_bedrock_guardrail_tr assert "US_SSN" in redacted.model_dump_json(), "the finding stays, only its matched text goes" assert "123-45-6789" not in str(redacted_dict) assert "123-45-6789" in response.model_dump_json(), "the caller's own response is not redacted" + + +PROMPT: Final = "my ssn is 123-45-6789\nand my pin is 4321, keep both safe" +LONG_PROMPT: Final = f"my ssn is 123-45-6789 'keep it' and \"safe\" {'and more ' * 200}until the end" + + +@pytest.mark.parametrize( + "quoted", + [PROMPT, json.dumps(PROMPT)[1:-1], repr(PROMPT)[1:-1]], + ids=["verbatim", "json", "repr"], +) +def test_scrub_request_text_replaces_each_way_an_error_quotes_the_prompt(quoted: str) -> None: + scrubbed: Final = scrub_request_text(f"Invalid content: <{quoted}> rejected", request_texts(PROMPT)) + + assert "123-45-6789" not in scrubbed and "4321" not in scrubbed + assert "redacted-by-litellm" in scrubbed + assert scrubbed.startswith("Invalid content: <") and scrubbed.endswith("> rejected") + + +@pytest.mark.parametrize( + "prompt", + ['say "hi" to Bob', "C:\\Users\\bob", "café for Bob", "tab\tfor Bob"], + ids=["double_quote", "backslash", "non_ascii", "control_character"], +) +@pytest.mark.parametrize("escaped", [json.dumps, repr], ids=["json", "repr"]) +def test_scrub_request_text_replaces_an_escaped_echo_of_a_prompt_that_escaping_changes( + prompt: str, escaped: Callable[[str], str] +) -> None: + error: Final = f"Invalid content: <{escaped(prompt)[1:-1]}> rejected" + + assert scrub_request_text(error, request_texts(prompt)) == "Invalid content: rejected" + + +@pytest.mark.parametrize( + "value", + [PROMPT, [PROMPT], {"content": PROMPT}, [{"content": PROMPT}], [{"content": LONG_PROMPT}], [LONG_PROMPT]], + ids=[ + "str", + "list", + "dict", + "nested_under_12_characters", + "text_longer_than_the_error", + "text_longer_than_the_error_cut_inside_an_escaped_quote", + ], +) +def test_scrub_request_text_replaces_both_sides_of_a_pydantic_cut_input_value(value: object) -> None: + with pytest.raises(ValidationError, match="input_value=") as raised: + TypeAdapter(int).validate_python(value) + + scrubbed: Final = scrub_request_text(str(raised.value), request_texts(value)) + + assert "my ssn" not in scrubbed and "4321" not in scrubbed + assert "redacted-by-litellm...redacted-by-litellm" in scrubbed + + +def test_scrub_request_text_leaves_an_error_that_does_not_quote_the_prompt() -> None: + assert scrub_request_text("Incorrect API key provided", request_texts(PROMPT, "hi")) == "Incorrect API key provided" + + +def test_scrub_request_text_replaces_a_short_text_only_between_quotes() -> None: + scrubbed: Final = scrub_request_text("Invalid value '432' and \"432\"; 432 is too short", request_texts("432")) + + assert scrubbed == "Invalid value 'redacted-by-litellm' and \"redacted-by-litellm\"; 432 is too short" + + +def test_scrub_request_text_replaces_the_whole_text_when_the_search_is_too_large() -> None: + texts: Final = request_texts([f"message number {index}" for index in range(5_000)]) + + assert scrub_request_text("x" * 5_000, texts) == "redacted-by-litellm" + + +def test_scrub_request_text_never_copies_a_request_text_longer_than_the_error() -> None: + error: Final = "litellm.RateLimitError: rate limit reached for gpt-4o" + image_urls: Final = request_texts([f"data:image/png;base64,{index}{'A' * 1_000_000}" for index in range(4)]) + already_tracing: Final = tracemalloc.is_tracing() + if not already_tracing: + tracemalloc.start() + tracemalloc.reset_peak() + baseline, _ = tracemalloc.get_traced_memory() + try: + scrubbed: Final = scrub_request_text(error, image_urls) + _, peak = tracemalloc.get_traced_memory() + finally: + if not already_tracing: + tracemalloc.stop() + + assert scrubbed == error + assert peak - baseline < 1_000_000, f"scrubbing a short error allocated {peak - baseline} bytes, copying the images" + + +def test_request_texts_reads_content_and_skips_structural_fields() -> None: + texts: Final = request_texts( + [ + {"role": "assistant", "content": [{"type": "text", "text": "part one text"}]}, + {"role": "tool", "tool_call_id": "call_123456", "name": "lookup", "content": "tool output"}, + litellm.Message(role="assistant", content="from a model object"), + ] + ) + + assert texts == {"part one text", "tool output", "from a model object"} + + +@pytest.mark.parametrize( + "request_data", + [ + {"turn_off_message_logging": True}, + {"metadata": {"turn_off_message_logging": True}}, + {"metadata": {"headers": {"x-litellm-enable-message-redaction": "true"}}}, + ], + ids=["body_flag", "metadata_flag", "enable_header"], +) +def test_should_redact_failed_request_follows_the_request_opt_ins(request_data: dict) -> None: + assert should_redact_failed_request(request_data) is True + assert should_redact_failed_request({}) is False + + +@pytest.mark.parametrize( + "request_data", + [{"metadata": {"headers": "x"}}, {"turn_off_message_logging": "os.environ/REDACT"}], + ids=["non_mapping_headers", "env_reference"], +) +@pytest.mark.parametrize("global_redaction", [True, False], ids=["global_on", "global_off"]) +def test_should_redact_failed_request_falls_back_to_the_global_setting_for_an_undecidable_request( + monkeypatch: pytest.MonkeyPatch, request_data: dict, global_redaction: bool +) -> None: + monkeypatch.setattr(litellm, "turn_off_message_logging", global_redaction) + + assert should_redact_failed_request(request_data) is global_redaction + + +def test_should_redact_failed_request_reads_the_request_setting_past_non_mapping_headers( + monkeypatch: pytest.MonkeyPatch, +) -> None: + monkeypatch.setattr(litellm, "turn_off_message_logging", False) + + assert should_redact_failed_request({"metadata": {"headers": "x"}, "turn_off_message_logging": True}) is True + + +@pytest.mark.parametrize( + "error_information", + [ + {"error_message": "bad: redacted-by-litellm", "traceback": "tb"}, + {"error_message": "bad input", "traceback": "tb redacted-by-litellm"}, + ], + ids=["message", "traceback_only"], +) +def test_scrubbed_exception_text_reports_a_scrub_of_either_field(error_information: dict) -> None: + logged: Final = scrubbed_exception_text({"standard_logging_object": {"error_information": error_information}}) + + assert logged == (error_information["error_message"], error_information["traceback"]) + assert scrubbed_exception_text({"standard_logging_object": {"error_information": {"error_message": "bad"}}}) is None + + +def test_scrubbed_exception_text_reports_a_scrub_of_the_logged_traceback() -> None: + model_call_details: Final = { + "traceback_exception": "ValueError: bad: redacted-by-litellm", + "standard_logging_object": {"error_information": {"error_message": "outer", "traceback": "frames"}}, + } + + assert scrubbed_exception_text(model_call_details) == ("outer", "ValueError: bad: redacted-by-litellm") + + +def test_scrubbed_exception_text_reads_the_message_off_the_traceback_without_a_logged_message() -> None: + traceback_text: Final = ( + "Traceback (most recent call last):\n" + ' File "main.py", line 1, in completion\n' + " raise BadRequestError(message)\n" + "BadRequestError: Invalid content: 'redacted-by-litellm'\n" + "Received Messages=['redacted-by-litellm']\n" + ) + + assert scrubbed_exception_text({"traceback_exception": traceback_text}) == ( + "BadRequestError: Invalid content: 'redacted-by-litellm'\nReceived Messages=['redacted-by-litellm']", + traceback_text, + ) + + +def test_scrubbed_error_information_for_request_scrubs_only_when_the_request_redacts() -> None: + error_information: Final = StandardLoggingPayloadErrorInformation( + error_code="400", error_class="BadRequestError", error_message=f"bad: {PROMPT}", traceback=f"tb {PROMPT}" + ) + messages: Final = [{"role": "user", "content": PROMPT}] + + scrubbed: Final = scrubbed_error_information_for_request( + error_information, {"messages": messages, "turn_off_message_logging": True} + ) + + assert scrubbed == { + **error_information, + "error_message": "bad: redacted-by-litellm", + "traceback": "tb redacted-by-litellm", + } + assert scrubbed_error_information_for_request(error_information, {"messages": messages}) == error_information From 9d973b0cafa0f0bc087c2b7f5644a6326e94ea9f Mon Sep 17 00:00:00 2001 From: yucheng Date: Sat, 31 Oct 2026 14:11:44 -0700 Subject: [PATCH 2/9] fix(logging): keep the request's redaction opt-in when another callback param is rejected --- litellm/litellm_core_utils/redact_messages.py | 31 ++++++++++++++++--- .../test_redact_messages.py | 16 ++++++++++ 2 files changed, 43 insertions(+), 4 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index 4491982d4c9..c9bcb9ec729 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -8,6 +8,7 @@ # Thank you users! We ❤️ you! - Krrish & Ishaan import asyncio +import contextlib import copy import inspect import itertools @@ -28,6 +29,7 @@ from litellm.litellm_core_utils.core_helpers import ( ) from litellm.litellm_core_utils.initialize_dynamic_callback_params import ( initialize_standard_callback_dynamic_params, + iter_client_callback_metadata_dicts, ) from litellm.litellm_core_utils.served_output_texts import SERVED_OUTPUT_TEXTS_KEY from litellm.llms.base_llm.guardrail_translation.utils import stream_item_field, stream_item_items @@ -896,12 +898,12 @@ def should_redact_failed_request(request_data: Mapping[str, object]) -> bool: """ The redaction decision for proxy failure hooks, which get the request body but not its logging object: the same metadata, headers and dynamic params the logging object would read. When the - logging object would reject the request's callback params, the global setting decides. + logging object would reject another of the request's callback params, the request's own + ``turn_off_message_logging`` still counts, and when it would reject that too the global setting decides. """ body: Final = dict(request_data) - try: - dynamic_params: Final = initialize_standard_callback_dynamic_params(body) - except ValueError: + dynamic_params: Final = _request_callback_params(body) + if dynamic_params is None: return litellm.turn_off_message_logging is True return should_redact_failure_logging( { @@ -911,6 +913,27 @@ def should_redact_failed_request(request_data: Mapping[str, object]) -> bool: ) +def _request_callback_params(body: Mapping[str, object]) -> StandardCallbackDynamicParams | None: + """ + The callback params the logging object reads from ``body``. When it would reject one of them, only the + request's own ``turn_off_message_logging``, and ``None`` when it would reject that too. + """ + with contextlib.suppress(ValueError): + return initialize_standard_callback_dynamic_params(dict(body)) + sources: Final[tuple[Mapping[str, object], ...]] = ( + body, + *(metadata for _, metadata in iter_client_callback_metadata_dicts(body)), + ) + redaction_choice: Final = next( + (source["turn_off_message_logging"] for source in sources if "turn_off_message_logging" in source), None + ) + with contextlib.suppress(ValueError): + return initialize_standard_callback_dynamic_params( + {} if redaction_choice is None else {"turn_off_message_logging": redaction_choice} + ) + return None + + def scrubbed_error_information_for_request( error_information: StandardLoggingPayloadErrorInformation, request_data: Mapping[str, object] ) -> StandardLoggingPayloadErrorInformation: diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index 71a76e5eaf2..b0852389186 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -2357,6 +2357,22 @@ def test_should_redact_failed_request_falls_back_to_the_global_setting_for_an_un assert should_redact_failed_request(request_data) is global_redaction +@pytest.mark.parametrize( + "request_data", + [ + {"turn_off_message_logging": True, "langfuse_host": "os.environ/LANGFUSE_HOST"}, + {"metadata": {"turn_off_message_logging": True, "langfuse_host": "os.environ/LANGFUSE_HOST"}}, + ], + ids=["body_flag", "metadata_flag"], +) +def test_should_redact_failed_request_keeps_the_request_opt_in_past_a_rejected_callback_param( + monkeypatch: pytest.MonkeyPatch, request_data: dict +) -> None: + monkeypatch.setattr(litellm, "turn_off_message_logging", False) + + assert should_redact_failed_request(request_data) is True + + def test_should_redact_failed_request_reads_the_request_setting_past_non_mapping_headers( monkeypatch: pytest.MonkeyPatch, ) -> None: From 8f46eccf77e80006886c438ca48480a1b3b6a6d7 Mon Sep 17 00:00:00 2001 From: yucheng Date: Sat, 31 Oct 2026 14:31:22 -0700 Subject: [PATCH 3/9] fix(logging): scrub pydantic cut sides that hold the prompt's own quotes --- litellm/litellm_core_utils/redact_messages.py | 40 ++++++++++++++--- .../test_redact_messages.py | 45 +++++++++++++++++++ 2 files changed, 78 insertions(+), 7 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index c9bcb9ec729..bec5d9f5e1d 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -432,8 +432,9 @@ _ESCAPED_CHARACTERS: Final = ('"', "\\") # pydantic shows a long input value as its repr's first 25 and last 24 characters around "...", quotes and # container keys included, so each side of the cut shows at most 24 characters of a quoted text _CUT_SIDE_LENGTH: Final = 24 -_CUT_ECHO_HEAD: Final = re.compile(rf"(?<=['\"])[^'\"]{{1,{_CUT_SIDE_LENGTH}}}(?=\.\.\.)") -_CUT_ECHO_TAIL: Final = re.compile(rf"(?<=\.\.\.)[^'\"]{{1,{_CUT_SIDE_LENGTH}}}(?=['\"])") +_CUT: Final = "..." +_CUT_STARTS: Final = re.compile(f"(?={re.escape(_CUT)})") +_QUOTES: Final = "'\"" _MAX_SCRUB_COMPARISONS: Final = 10_000_000 @@ -490,13 +491,18 @@ def _cut_sides(text: str) -> str: return f"{text[:_CUT_SIDE_LENGTH]}{quotes}{text[-_CUT_SIDE_LENGTH:]}" -def _cut_echoes(text: str, forms: Collection[str]) -> tuple[tuple[str, str], ...]: +def _cut_echoes(text: str, forms: Collection[str]) -> tuple[tuple[str, str], ...] | None: """ Each side of a quoted value ``text`` cuts short with ``...`` that starts or ends one of ``forms``, as - pydantic shows a long input value, with its pattern anchored to the quote and the cut. + pydantic shows a long input value, with its pattern anchored to the quote and the cut. A side can hold + the request's own quotes, so every quote within a side's length of the cut is tried as its opening or + closing one. ``None`` when checking every side against ``forms`` is too large a search for a failure path. """ - heads: Final = frozenset(match.group() for match in _CUT_ECHO_HEAD.finditer(text)) - tails: Final = frozenset(match.group() for match in _CUT_ECHO_TAIL.finditer(text)) + cuts: Final = tuple(match.start() for match in _CUT_STARTS.finditer(text)) + heads: Final = frozenset(itertools.chain.from_iterable(_cut_heads(text, cut) for cut in cuts)) + tails: Final = frozenset(itertools.chain.from_iterable(_cut_tails(text, cut) for cut in cuts)) + if (len(heads) + len(tails)) * len(forms) > _MAX_SCRUB_COMPARISONS: + return None return ( *( (head, f"(?<=['\"]){re.escape(head)}(?=\\.\\.\\.)") @@ -511,6 +517,23 @@ def _cut_echoes(text: str, forms: Collection[str]) -> tuple[tuple[str, str], ... ) +def _cut_heads(text: str, cut: int) -> tuple[str, ...]: + """Each run of ``text`` from just after a quote up to the ``...`` at ``cut``, no longer than a cut side.""" + return tuple( + text[quote + 1 : cut] for quote in range(max(0, cut - _CUT_SIDE_LENGTH - 1), cut - 1) if text[quote] in _QUOTES + ) + + +def _cut_tails(text: str, cut: int) -> tuple[str, ...]: + """Each run of ``text`` from the end of the ``...`` at ``cut`` up to just before a quote, no longer than a cut side.""" + start: Final = cut + len(_CUT) + return tuple( + text[start:quote] + for quote in range(start + 1, min(len(text), start + _CUT_SIDE_LENGTH + 1)) + if text[quote] in _QUOTES + ) + + def scrub_request_text(text: str, texts: Collection[str]) -> str: """ ``text`` with every quote of the request's own ``texts`` replaced by ``REDACTED_BY_LITELLM``, so an @@ -527,8 +550,11 @@ def scrub_request_text(text: str, texts: Collection[str]) -> str: cut_forms: Final = frozenset( itertools.chain.from_iterable(_echo_forms(_cut_sides(each)) for each in texts if len(each) > len(text)) ) + cut_echoes: Final = _cut_echoes(text, forms | cut_forms) + if cut_echoes is None: + return REDACTED_BY_LITELLM echoes: Final = sorted( - (*((form, _echo_pattern(form)) for form in forms if form in text), *_cut_echoes(text, forms | cut_forms)), + (*((form, _echo_pattern(form)) for form in forms if form in text), *cut_echoes), key=lambda echo: len(echo[0]), reverse=True, ) diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index b0852389186..f033a3cad72 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -10,6 +10,7 @@ import copy import importlib import json import os +import random import threading import tracemalloc from collections.abc import AsyncIterator, Callable, Mapping @@ -2282,6 +2283,42 @@ def test_scrub_request_text_replaces_both_sides_of_a_pydantic_cut_input_value(va assert "redacted-by-litellm...redacted-by-litellm" in scrubbed +SINGLE_QUOTED_PROMPT: Final = "account 'secret' " + "x" * 1_000 + " end 'private'" +BOTH_QUOTED_PROMPT: Final = 'said "secret" it\'s ' + "x" * 1_000 + ' it\'s "private"' +DOTTED_PROMPT: Final = "account secret is there." + "x" * 1_000 + ".private secret is here" + + +@pytest.mark.parametrize( + "value", + [ + SINGLE_QUOTED_PROMPT, + [SINGLE_QUOTED_PROMPT], + {"content": SINGLE_QUOTED_PROMPT}, + BOTH_QUOTED_PROMPT, + [BOTH_QUOTED_PROMPT], + {"content": BOTH_QUOTED_PROMPT}, + DOTTED_PROMPT, + ], + ids=[ + "single_quotes_str", + "single_quotes_list", + "single_quotes_dict", + "both_quotes_str", + "both_quotes_list", + "both_quotes_dict", + "dots_beside_both_cuts", + ], +) +def test_scrub_request_text_replaces_pydantic_cut_sides_that_hold_the_prompts_own_quotes(value: object) -> None: + with pytest.raises(ValidationError, match="input_value=") as raised: + TypeAdapter(int).validate_python(value) + + scrubbed: Final = scrub_request_text(str(raised.value), request_texts(value)) + + assert not any(word in scrubbed for word in ("account", "said", "secret", "private")) + assert "redacted-by-litellm...redacted-by-litellm" in scrubbed + + def test_scrub_request_text_leaves_an_error_that_does_not_quote_the_prompt() -> None: assert scrub_request_text("Incorrect API key provided", request_texts(PROMPT, "hi")) == "Incorrect API key provided" @@ -2298,6 +2335,14 @@ def test_scrub_request_text_replaces_the_whole_text_when_the_search_is_too_large assert scrub_request_text("x" * 5_000, texts) == "redacted-by-litellm" +def test_scrub_request_text_replaces_the_whole_text_when_the_cut_side_search_is_too_large() -> None: + rng: Final = random.Random(0) + error: Final = "".join(rng.choice("'ab") if index % 10 else "..." for index in range(10_000)) + texts: Final = request_texts([f'say "hi" {index}' for index in range(800)]) + + assert scrub_request_text(error, texts) == "redacted-by-litellm" + + def test_scrub_request_text_never_copies_a_request_text_longer_than_the_error() -> None: error: Final = "litellm.RateLimitError: rate limit reached for gpt-4o" image_urls: Final = request_texts([f"data:image/png;base64,{index}{'A' * 1_000_000}" for index in range(4)]) From 1ebe49ca1a2c08e5fbb6c5041f308aa005169007 Mon Sep 17 00:00:00 2001 From: yucheng Date: Mon, 2 Nov 2026 14:18:57 -0800 Subject: [PATCH 4/9] fix(logging): replace a pydantic input_value whole instead of walking each cut The scrub walked every "..." in the error and tried each quote around it to find the two ends pydantic shows of a long input. A request of dots made that walk cost about 48 Python steps per character on the event loop, with no cap tripping. Replace everything from a line's first input_value= to its last , input_type= (or to the line's end without one) instead. Finding both labels is linear, the scrub no longer needs the prompt's cut sides, and the cut-side work cap goes with them. A value that is not request text, such as None or a bad role, is now blanked too. A quote of the prompt that holds input_value= is replaced first, so the label replace can't split it. Other quotes go after, and a text's trailing label is left out of its quote, so a message such as "value" or ", input_value=" can't break the label of a real error. --- litellm/litellm_core_utils/redact_messages.py | 102 ++++-------- .../test_redact_messages.py | 147 ++++++++++++++++-- 2 files changed, 166 insertions(+), 83 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index bec5d9f5e1d..c3044cede45 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -429,12 +429,8 @@ _REQUEST_TEXT_KEYS: Final = ("messages", "input", "prompt", "system", "instructi _STRUCTURAL_KEYS: Final = frozenset({"role", "type", "id", "tool_call_id", "name"}) _MIN_UNQUOTED_TEXT_LENGTH: Final = 4 _ESCAPED_CHARACTERS: Final = ('"', "\\") -# pydantic shows a long input value as its repr's first 25 and last 24 characters around "...", quotes and -# container keys included, so each side of the cut shows at most 24 characters of a quoted text -_CUT_SIDE_LENGTH: Final = 24 -_CUT: Final = "..." -_CUT_STARTS: Final = re.compile(f"(?={re.escape(_CUT)})") -_QUOTES: Final = "'\"" +_INPUT_VALUE_LABEL: Final = "input_value=" +_INPUT_TYPE_LABEL: Final = ", input_type=" _MAX_SCRUB_COMPARISONS: Final = 10_000_000 @@ -482,63 +478,11 @@ def _echo_forms(text: str) -> frozenset[str]: return frozenset({text, json.dumps(text)[1:-1], json.dumps(text, ensure_ascii=False)[1:-1], repr(text)[1:-1]}) -def _cut_sides(text: str) -> str: - """ - The start and end of ``text`` that a pydantic cut can show, for a text too long to be quoted whole, with - ``text``'s quote characters between them so repr escapes the sides as it escapes the whole ``text``. - """ - quotes: Final = "".join(quote for quote in "'\"" if quote in text) - return f"{text[:_CUT_SIDE_LENGTH]}{quotes}{text[-_CUT_SIDE_LENGTH:]}" - - -def _cut_echoes(text: str, forms: Collection[str]) -> tuple[tuple[str, str], ...] | None: - """ - Each side of a quoted value ``text`` cuts short with ``...`` that starts or ends one of ``forms``, as - pydantic shows a long input value, with its pattern anchored to the quote and the cut. A side can hold - the request's own quotes, so every quote within a side's length of the cut is tried as its opening or - closing one. ``None`` when checking every side against ``forms`` is too large a search for a failure path. - """ - cuts: Final = tuple(match.start() for match in _CUT_STARTS.finditer(text)) - heads: Final = frozenset(itertools.chain.from_iterable(_cut_heads(text, cut) for cut in cuts)) - tails: Final = frozenset(itertools.chain.from_iterable(_cut_tails(text, cut) for cut in cuts)) - if (len(heads) + len(tails)) * len(forms) > _MAX_SCRUB_COMPARISONS: - return None - return ( - *( - (head, f"(?<=['\"]){re.escape(head)}(?=\\.\\.\\.)") - for head in heads - if any(form.startswith(head) for form in forms) - ), - *( - (tail, f"(?<=\\.\\.\\.){re.escape(tail)}(?=['\"])") - for tail in tails - if any(form.endswith(tail) for form in forms) - ), - ) - - -def _cut_heads(text: str, cut: int) -> tuple[str, ...]: - """Each run of ``text`` from just after a quote up to the ``...`` at ``cut``, no longer than a cut side.""" - return tuple( - text[quote + 1 : cut] for quote in range(max(0, cut - _CUT_SIDE_LENGTH - 1), cut - 1) if text[quote] in _QUOTES - ) - - -def _cut_tails(text: str, cut: int) -> tuple[str, ...]: - """Each run of ``text`` from the end of the ``...`` at ``cut`` up to just before a quote, no longer than a cut side.""" - start: Final = cut + len(_CUT) - return tuple( - text[start:quote] - for quote in range(start + 1, min(len(text), start + _CUT_SIDE_LENGTH + 1)) - if text[quote] in _QUOTES - ) - - def scrub_request_text(text: str, texts: Collection[str]) -> str: """ - ``text`` with every quote of the request's own ``texts`` replaced by ``REDACTED_BY_LITELLM``, so an - error that does not echo the prompt keeps its wording. A search too large for a failure path - replaces the whole text. + ``text`` with every quote of the request's own ``texts`` and every pydantic ``input_value`` replaced by + ``REDACTED_BY_LITELLM``, so an error that holds neither keeps its wording. A search too large for a + failure path replaces the whole text. """ if not text or not texts: return text @@ -547,20 +491,38 @@ def scrub_request_text(text: str, texts: Collection[str]) -> str: forms: Final = frozenset( itertools.chain.from_iterable(_echo_forms(each) for each in texts if len(each) <= len(text)) ) - cut_forms: Final = frozenset( - itertools.chain.from_iterable(_echo_forms(_cut_sides(each)) for each in texts if len(each) > len(text)) - ) - cut_echoes: Final = _cut_echoes(text, forms | cut_forms) - if cut_echoes is None: - return REDACTED_BY_LITELLM echoes: Final = sorted( - (*((form, _echo_pattern(form)) for form in forms if form in text), *cut_echoes), - key=lambda echo: len(echo[0]), + (form for form in (each.removesuffix(_INPUT_VALUE_LABEL) for each in forms) if form and form in text), + key=len, reverse=True, ) + label_quotes: Final = tuple(form for form in echoes if _INPUT_VALUE_LABEL in form) + other_quotes: Final = tuple(form for form in echoes if _INPUT_VALUE_LABEL not in form) + return _with_echoes_replaced(_with_input_values_replaced(_with_echoes_replaced(text, label_quotes)), other_quotes) + + +def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str: + """``text`` with one pass that replaces each of ``echoes``, in order, by ``REDACTED_BY_LITELLM``.""" if not echoes: return text - return re.sub("|".join(pattern for _, pattern in echoes), REDACTED_BY_LITELLM, text) + return re.sub("|".join(_echo_pattern(form) for form in echoes), REDACTED_BY_LITELLM, text) + + +def _with_input_values_replaced(text: str) -> str: + """``text`` with the pydantic ``input_value`` on each of its lines replaced by ``REDACTED_BY_LITELLM``.""" + if _INPUT_VALUE_LABEL not in text: + return text + return "\n".join(_line_with_input_value_replaced(line) for line in text.split("\n")) + + +def _line_with_input_value_replaced(line: str) -> str: + """``line`` from its first ``input_value=`` up to its last ``, input_type=``, or to its end without one, replaced.""" + start: Final = line.find(_INPUT_VALUE_LABEL) + if start < 0: + return line + value_start: Final = start + len(_INPUT_VALUE_LABEL) + type_start: Final = line.rfind(_INPUT_TYPE_LABEL, value_start) + return f"{line[:value_start]}{REDACTED_BY_LITELLM}{line[type_start:] if type_start >= 0 else ''}" def _echo_pattern(form: str) -> str: diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index f033a3cad72..d9fe5a56f82 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -10,8 +10,8 @@ import copy import importlib import json import os -import random import threading +import time import tracemalloc from collections.abc import AsyncIterator, Callable, Mapping from datetime import datetime @@ -2273,14 +2273,14 @@ def test_scrub_request_text_replaces_an_escaped_echo_of_a_prompt_that_escaping_c "text_longer_than_the_error_cut_inside_an_escaped_quote", ], ) -def test_scrub_request_text_replaces_both_sides_of_a_pydantic_cut_input_value(value: object) -> None: +def test_scrub_request_text_replaces_a_pydantic_cut_input_value(value: object) -> None: with pytest.raises(ValidationError, match="input_value=") as raised: TypeAdapter(int).validate_python(value) scrubbed: Final = scrub_request_text(str(raised.value), request_texts(value)) assert "my ssn" not in scrubbed and "4321" not in scrubbed - assert "redacted-by-litellm...redacted-by-litellm" in scrubbed + assert "input_value=redacted-by-litellm, input_type=" in scrubbed SINGLE_QUOTED_PROMPT: Final = "account 'secret' " + "x" * 1_000 + " end 'private'" @@ -2309,14 +2309,143 @@ DOTTED_PROMPT: Final = "account secret is there." + "x" * 1_000 + ".private secr "dots_beside_both_cuts", ], ) -def test_scrub_request_text_replaces_pydantic_cut_sides_that_hold_the_prompts_own_quotes(value: object) -> None: +def test_scrub_request_text_replaces_a_pydantic_input_value_that_holds_the_prompts_own_quotes(value: object) -> None: with pytest.raises(ValidationError, match="input_value=") as raised: TypeAdapter(int).validate_python(value) scrubbed: Final = scrub_request_text(str(raised.value), request_texts(value)) assert not any(word in scrubbed for word in ("account", "said", "secret", "private")) - assert "redacted-by-litellm...redacted-by-litellm" in scrubbed + assert "input_value=redacted-by-litellm, input_type=" in scrubbed + + +def test_scrub_request_text_replaces_every_line_of_a_pydantic_error_and_keeps_its_wording() -> None: + prompt: Final = "account secret " + "x" * 200 + " private" + with pytest.raises(ValidationError) as raised: + TypeAdapter(tuple[int, int]).validate_python([prompt, prompt]) + + scrubbed: Final = scrub_request_text(str(raised.value), request_texts(prompt)) + + assert not any(word in scrubbed for word in ("account", "secret", "private")) + assert scrubbed.count("input_value=redacted-by-litellm, input_type=str]") == 2 + assert "Input should be a valid integer" in scrubbed + + +@pytest.mark.parametrize( + "wrapped", + [repr, lambda error: json.dumps({"detail": error}), lambda error: str({"error": {"message": error}})], + ids=["repr", "json", "dict_str"], +) +def test_scrub_request_text_replaces_the_input_values_of_a_pydantic_error_wrapped_onto_one_line( + wrapped: Callable[[str], str], +) -> None: + prompt: Final = "account 'secret' " + "x" * 200 + ' end "private"' + with pytest.raises(ValidationError) as raised: + TypeAdapter(tuple[int, int]).validate_python([prompt, prompt]) + + scrubbed: Final = scrub_request_text(wrapped(str(raised.value)), request_texts(prompt)) + + assert not any(word in scrubbed for word in ("account", "secret", "private")) + assert "input_value=redacted-by-litellm" in scrubbed + + +def test_scrub_request_text_replaces_an_input_value_that_holds_the_input_type_label() -> None: + prompt: Final = "account, input_type=str] secret input_value='a' " + "x" * 200 + " private" + with pytest.raises(ValidationError) as raised: + TypeAdapter(int).validate_python(prompt) + + scrubbed: Final = scrub_request_text(str(raised.value), request_texts(prompt)) + + assert not any(word in scrubbed for word in ("account", "secret", "private")) + assert "input_value=redacted-by-litellm, input_type=str]" in scrubbed + + +@pytest.mark.parametrize( + "other_message", + [ + "value", + "input", + "input_value", + "input_value=", + ", input_value=", + "int_parsing, input_value=", + "_value=", + "type", + "input_type", + ", input_type=", + ], +) +def test_scrub_request_text_replaces_an_input_value_when_another_message_matches_its_label(other_message: str) -> None: + prompt: Final = "account secret " + "x" * 200 + " private" + with pytest.raises(ValidationError) as raised: + TypeAdapter(int).validate_python(prompt) + + scrubbed: Final = scrub_request_text(str(raised.value), request_texts([other_message, prompt])) + + assert not any(word in scrubbed for word in ("account", "secret", "private")) + + +def test_scrub_request_text_leaves_empty_quotes_when_a_message_is_only_the_input_value_label() -> None: + error: Final = "empty value '' rejected" + + assert scrub_request_text(error, request_texts("input_value=")) == error + + +def test_scrub_request_text_replaces_to_the_end_of_the_line_without_an_input_type() -> None: + error: Final = "bad value [type=int_parsing, input_value='account sec\nnext line" + + assert scrub_request_text(error, request_texts("hi there")) == ( + "bad value [type=int_parsing, input_value=redacted-by-litellm\nnext line" + ) + + +@pytest.mark.parametrize( + "prompt", + ["account secret input_value=1 private", "input_value=account secret private"], + ids=["middle", "start"], +) +def test_scrub_request_text_replaces_the_whole_of_a_quoted_prompt_that_holds_the_input_value_label(prompt: str) -> None: + assert scrub_request_text(f"Invalid content: <{prompt}> rejected", request_texts(prompt)) == ( + "Invalid content: rejected" + ) + + +def test_scrub_request_text_replaces_a_quoted_prompt_that_ends_in_the_input_value_label() -> None: + prompt: Final = "account secret private input_value=" + + scrubbed: Final = scrub_request_text(f"Invalid content: <{prompt}> rejected", request_texts(prompt)) + + assert scrubbed.startswith("Invalid content: None: + with pytest.raises(ValidationError) as raised: + TypeAdapter(int).validate_python(value) + + assert "input_value=redacted-by-litellm, input_type=" in scrub_request_text( + str(raised.value), request_texts("hi there") + ) + + +def test_scrub_request_text_keeps_an_input_value_when_the_request_has_no_text() -> None: + error: Final = "bad value [type=int_type, input_value=None, input_type=NoneType]" + + assert scrub_request_text(error, request_texts(None)) == error + + +@pytest.mark.parametrize( + "error", + ["." * 1_000_000, "input_value=" * 100_000, "input_value=x, input_type=y\n" * 40_000, " ...'x" * 200_000], + ids=["dots", "input_value_labels_on_one_line", "input_values_on_many_lines", "quoted_cuts"], +) +def test_scrub_request_text_stays_fast_on_a_large_error(error: str) -> None: + started: Final = time.perf_counter() + + scrub_request_text(error, request_texts("hi there")) + + assert time.perf_counter() - started < 0.5 def test_scrub_request_text_leaves_an_error_that_does_not_quote_the_prompt() -> None: @@ -2335,14 +2464,6 @@ def test_scrub_request_text_replaces_the_whole_text_when_the_search_is_too_large assert scrub_request_text("x" * 5_000, texts) == "redacted-by-litellm" -def test_scrub_request_text_replaces_the_whole_text_when_the_cut_side_search_is_too_large() -> None: - rng: Final = random.Random(0) - error: Final = "".join(rng.choice("'ab") if index % 10 else "..." for index in range(10_000)) - texts: Final = request_texts([f'say "hi" {index}' for index in range(800)]) - - assert scrub_request_text(error, texts) == "redacted-by-litellm" - - def test_scrub_request_text_never_copies_a_request_text_longer_than_the_error() -> None: error: Final = "litellm.RateLimitError: rate limit reached for gpt-4o" image_urls: Final = request_texts([f"data:image/png;base64,{index}{'A' * 1_000_000}" for index in range(4)]) From 621b0dde97dea929a01e4d25437386d9edc0c7a3 Mon Sep 17 00:00:00 2001 From: yucheng Date: Wed, 4 Nov 2026 16:57:29 -0800 Subject: [PATCH 5/9] test(logging): move the large-error scrub timing check to a CodSpeed benchmark tests/unit/AGENTS.md forbids unit tests that depend on execution speed, so the four large errors now run as a benchmark that asserts the scrubbed output. --- .../test_redact_messages_benchmarks.py | 22 +++++++++++++++++++ .../test_redact_messages.py | 14 ------------ 2 files changed, 22 insertions(+), 14 deletions(-) create mode 100644 tests/benchmarks/test_redact_messages_benchmarks.py diff --git a/tests/benchmarks/test_redact_messages_benchmarks.py b/tests/benchmarks/test_redact_messages_benchmarks.py new file mode 100644 index 00000000000..d360e5cb9ef --- /dev/null +++ b/tests/benchmarks/test_redact_messages_benchmarks.py @@ -0,0 +1,22 @@ +from typing import Final + +import pytest + +from litellm.litellm_core_utils.redact_messages import request_texts, scrub_request_text + +REQUEST_TEXTS: Final = request_texts("hi there") + + +@pytest.mark.benchmark +@pytest.mark.parametrize( + ("error", "scrubbed"), + [ + ("." * 100_000, "." * 100_000), + (" ...'x" * 20_000, " ...'x" * 20_000), + ("input_value=" * 10_000, "input_value=redacted-by-litellm"), + ("input_value=x, input_type=y\n" * 4_000, "input_value=redacted-by-litellm, input_type=y\n" * 4_000), + ], + ids=["dots", "quoted_cuts", "input_value_labels_on_one_line", "input_values_on_many_lines"], +) +def test_scrubbing_a_large_error(error: str, scrubbed: str) -> None: + assert scrub_request_text(error, REQUEST_TEXTS) == scrubbed diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index d9fe5a56f82..b2daddf2d09 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -11,7 +11,6 @@ import importlib import json import os import threading -import time import tracemalloc from collections.abc import AsyncIterator, Callable, Mapping from datetime import datetime @@ -2435,19 +2434,6 @@ def test_scrub_request_text_keeps_an_input_value_when_the_request_has_no_text() assert scrub_request_text(error, request_texts(None)) == error -@pytest.mark.parametrize( - "error", - ["." * 1_000_000, "input_value=" * 100_000, "input_value=x, input_type=y\n" * 40_000, " ...'x" * 200_000], - ids=["dots", "input_value_labels_on_one_line", "input_values_on_many_lines", "quoted_cuts"], -) -def test_scrub_request_text_stays_fast_on_a_large_error(error: str) -> None: - started: Final = time.perf_counter() - - scrub_request_text(error, request_texts("hi there")) - - assert time.perf_counter() - started < 0.5 - - def test_scrub_request_text_leaves_an_error_that_does_not_quote_the_prompt() -> None: assert scrub_request_text("Incorrect API key provided", request_texts(PROMPT, "hi")) == "Incorrect API key provided" From 424dd5fc686713f7afc349272eefc4e4a45d3732 Mon Sep 17 00:00:00 2001 From: yucheng Date: Wed, 4 Nov 2026 19:07:39 -0800 Subject: [PATCH 6/9] fix(logging): scrub request text as whole words without re's pattern cache, and rebuild an exception's frames when no traceback was logged --- litellm/litellm_core_utils/redact_messages.py | 131 +++++++++++++++-- .../test_redact_messages.py | 137 ++++++++++++++++++ 2 files changed, 255 insertions(+), 13 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index c3044cede45..ace55b53dfc 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -10,11 +10,13 @@ import asyncio import contextlib import copy +import functools import inspect import itertools import json import re -from collections.abc import Collection, Iterable, Mapping, Sequence +import traceback +from collections.abc import Collection, Iterable, Iterator, Mapping, Sequence from dataclasses import replace from typing import TYPE_CHECKING, Any, Final @@ -432,6 +434,11 @@ _ESCAPED_CHARACTERS: Final = ('"', "\\") _INPUT_VALUE_LABEL: Final = "input_value=" _INPUT_TYPE_LABEL: Final = ", input_type=" _MAX_SCRUB_COMPARISONS: Final = 10_000_000 +_MAX_ECHO_OCCURRENCES: Final = 10_000 +_QUOTES: Final = ("'", '"') +_ESCAPE_TAIL: Final = re.compile(r"\\(?:[abfnrtv]|x[0-9a-fA-F]{2}|u[0-9a-fA-F]{4}|U[0-9a-fA-F]{8})\Z") +_DIRECT_CAUSE_LINE: Final = "\nThe above exception was the direct cause of the following exception:\n\n" +_CONTEXT_LINE: Final = "\nDuring handling of the above exception, another exception occurred:\n\n" def _child_values(value: object) -> tuple[object, ...]: @@ -498,14 +505,83 @@ def scrub_request_text(text: str, texts: Collection[str]) -> str: ) label_quotes: Final = tuple(form for form in echoes if _INPUT_VALUE_LABEL in form) other_quotes: Final = tuple(form for form in echoes if _INPUT_VALUE_LABEL not in form) - return _with_echoes_replaced(_with_input_values_replaced(_with_echoes_replaced(text, label_quotes)), other_quotes) + with_label_quotes_replaced: Final = _with_echoes_replaced(text, label_quotes) + scrubbed: Final = ( + None + if with_label_quotes_replaced is None + else _with_echoes_replaced(_with_input_values_replaced(with_label_quotes_replaced), other_quotes) + ) + return REDACTED_BY_LITELLM if scrubbed is None else scrubbed -def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str: - """``text`` with one pass that replaces each of ``echoes``, in order, by ``REDACTED_BY_LITELLM``.""" - if not echoes: - return text - return re.sub("|".join(_echo_pattern(form) for form in echoes), REDACTED_BY_LITELLM, text) +def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str | None: + """ + ``text`` with each quote of ``echoes`` replaced by ``REDACTED_BY_LITELLM`` in one left-to-right pass, the + longest where several start at one place. ``None`` when ``echoes`` turn up more often than a failure path + should look through. + """ + found: Final = tuple( + itertools.islice( + itertools.chain.from_iterable(_quote_spans(text, form) for form in echoes), _MAX_ECHO_OCCURRENCES + 1 + ) + ) + if len(found) > _MAX_ECHO_OCCURRENCES: + return None + ends: Final = dict(sorted((span for span in found if _stands_alone(text, *span)), key=lambda span: span[1])) + starts: Final = sorted(ends) + frontiers: Final = itertools.accumulate(starts, functools.partial(_frontier_after, ends), initial=0) + chosen: Final = tuple(start for start, frontier in zip(starts, frontiers) if start >= frontier) + resumes: Final = (0, *(ends[start] for start in chosen)) + kept_and_replaced: Final = itertools.chain.from_iterable( + (text[resume:start], REDACTED_BY_LITELLM) for resume, start in zip(resumes, chosen) + ) + return "".join((*kept_and_replaced, text[resumes[-1] :])) + + +def _frontier_after(ends: Mapping[int, int], frontier: int, start: int) -> int: + """Where the next replacement may start once the quote at ``start`` is passed, replacing it if it starts at or + past ``frontier``.""" + return ends[start] if start >= frontier else frontier + + +def _quote_spans(text: str, form: str) -> Iterator[tuple[int, int]]: + """Where each quote of ``form`` in ``text`` starts and ends, overlaps included. A form short enough to occur in + ordinary wording only counts between quotes.""" + if len(form) >= _MIN_UNQUOTED_TEXT_LENGTH: + return ((start, start + len(form)) for start in _found(text, form)) + quoted_starts: Final = itertools.chain.from_iterable( + _found(text, f"{opening}{form}{closing}") for opening, closing in itertools.product(_QUOTES, repeat=2) + ) + return ((start + 1, start + 1 + len(form)) for start in quoted_starts) + + +def _found(text: str, piece: str) -> Iterator[int]: + """Every index ``piece`` starts at in ``text``, overlaps included.""" + return itertools.takewhile( + lambda start: start >= 0, + itertools.accumulate( + itertools.repeat(None), lambda start, _: text.find(piece, start + 1), initial=text.find(piece) + ), + ) + + +def _stands_alone(text: str, start: int, end: int) -> bool: + """Whether ``text[start:end]`` is not part of a longer word. An escape such as ``\\n`` before it counts as a break.""" + return (not _is_word_character(text[start]) or _is_word_break(text, start)) and ( + not _is_word_character(text[end - 1]) or end == len(text) or not _is_word_character(text[end]) + ) + + +def _is_word_break(text: str, index: int) -> bool: + return ( + index == 0 + or not _is_word_character(text[index - 1]) + or _ESCAPE_TAIL.search(text, max(0, index - 10), index) is not None + ) + + +def _is_word_character(character: str) -> bool: + return character.isascii() and (character.isalnum() or character == "_") def _with_input_values_replaced(text: str) -> str: @@ -525,12 +601,6 @@ def _line_with_input_value_replaced(line: str) -> str: return f"{line[:value_start]}{REDACTED_BY_LITELLM}{line[type_start:] if type_start >= 0 else ''}" -def _echo_pattern(form: str) -> str: - """A quote of ``form``. A form short enough to occur in ordinary wording only counts between quotes.""" - escaped: Final = re.escape(form) - return escaped if len(form) >= _MIN_UNQUOTED_TEXT_LENGTH else f"(?<=['\"]){escaped}(?=['\"])" - - def scrubbed_error_information( error_information: StandardLoggingPayloadErrorInformation, texts: Collection[str] ) -> StandardLoggingPayloadErrorInformation: @@ -588,6 +658,41 @@ def scrubbed_exception_text(model_call_details: Mapping[str, object]) -> tuple[s return (message if isinstance(message, str) else _exception_text(logged_traceback_text), logged_traceback_text) +def scrubbed_exception_record(model_call_details: Mapping[str, object]) -> tuple[str, str] | None: + """ + The message and stack trace to record for the failure's exception when redaction scrubbed the request's text + out of the logged error, as ``scrubbed_exception_text`` reads them. A failure that logged no traceback gets the + exception's own frames, with ``REDACTED_BY_LITELLM`` for the text of each exception it chains. + """ + scrubbed: Final = scrubbed_exception_text(model_call_details) + exception: Final = model_call_details.get("exception") + if scrubbed is None or scrubbed[1] or not isinstance(exception, BaseException): + return scrubbed + return scrubbed[0], _exception_stack(exception, scrubbed[0], frozenset()) + + +def _exception_stack(exception: BaseException, message: str, newer: frozenset[int]) -> str: + """``exception``'s traceback as Python prints it, with ``message`` for its text and ``REDACTED_BY_LITELLM`` for + the text of each exception it chains. ``newer`` holds the exceptions already printed after it.""" + printed: Final = newer | {id(exception)} + caused: Final = exception.__cause__ is not None + chained: Final = ( + exception.__cause__ if caused else None if exception.__suppress_context__ else exception.__context__ + ) + earlier: Final = ( + "" + if chained is None or id(chained) in printed + else _exception_stack(chained, REDACTED_BY_LITELLM, printed) + (_DIRECT_CAUSE_LINE if caused else _CONTEXT_LINE) + ) + frames: Final = "".join(traceback.format_tb(exception.__traceback__)) + header: Final = "Traceback (most recent call last):\n" if frames else "" + kind: Final = type(exception) + name: Final = ( + kind.__qualname__ if kind.__module__ in ("__main__", "builtins") else f"{kind.__module__}.{kind.__qualname__}" + ) + return f"{earlier}{header}{frames}{name}: {message}\n" if message else f"{earlier}{header}{frames}{name}\n" + + def _exception_text(traceback_text: str) -> str: """The lines after the last indented frame line of ``traceback_text``.""" lines: Final = reversed(traceback_text.rstrip().splitlines()) diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index b2daddf2d09..07b300d94ea 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -11,6 +11,7 @@ import importlib import json import os import threading +import traceback import tracemalloc from collections.abc import AsyncIterator, Callable, Mapping from datetime import datetime @@ -37,6 +38,7 @@ from litellm.litellm_core_utils.redact_messages import ( request_texts, scrub_request_text, scrubbed_error_information_for_request, + scrubbed_exception_record, scrubbed_exception_text, should_redact_failed_request, should_redact_message_logging, @@ -2444,6 +2446,71 @@ def test_scrub_request_text_replaces_a_short_text_only_between_quotes() -> None: assert scrubbed == "Invalid value 'redacted-by-litellm' and \"redacted-by-litellm\"; 432 is too short" +@pytest.mark.parametrize( + ("prompt", "error"), + [ + ("Error", "litellm.RateLimitError: Rate limit reached"), + ("test", "The model `gpt-4-latest` does not exist"), + ("text", "litellm.ContextWindowExceededError: too long"), + ("test", "No deployment named test_model"), + ], + ids=["word_end", "word_start", "word_middle", "before_underscore"], +) +def test_scrub_request_text_leaves_a_prompt_that_only_occurs_inside_a_longer_word(prompt: str, error: str) -> None: + assert scrub_request_text(error, request_texts(prompt)) == error + + +@pytest.mark.parametrize( + ("error", "scrubbed"), + [ + ("Error", "redacted-by-litellm"), + ("Invalid content: Error.", "Invalid content: redacted-by-litellm."), + ('content: "first\\nError"', 'content: "first\\nredacted-by-litellm"'), + ('content: "\\u00e9Error"', 'content: "\\u00e9redacted-by-litellm"'), + ("content: 'caf\\xe9Error'", "content: 'caf\\xe9redacted-by-litellm'"), + ("内容错误Error请重试", "内容错误redacted-by-litellm请重试"), + ], + ids=["whole_text", "whole_word", "after_newline_escape", "after_unicode_escape", "after_hex_escape", "non_ascii"], +) +def test_scrub_request_text_replaces_a_prompt_that_stands_as_its_own_word(error: str, scrubbed: str) -> None: + assert scrub_request_text(error, request_texts("Error")) == scrubbed + + +def test_scrub_request_text_replaces_the_longest_prompt_that_starts_at_one_place() -> None: + scrubbed: Final = scrub_request_text("bad: secret code list", request_texts("secret", "secret code", "code list")) + + assert scrubbed == "bad: redacted-by-litellm list" + + +@pytest.mark.parametrize( + ("echoes", "scrubbed"), + [(10_000, "bad: redacted-by-litellm " * 10_000), (10_001, "redacted-by-litellm")], + ids=["at_the_limit", "past_the_limit"], +) +def test_scrub_request_text_replaces_the_whole_text_when_the_prompt_repeats_past_the_limit( + echoes: int, scrubbed: str +) -> None: + assert scrub_request_text("bad: secret " * echoes, request_texts("secret")) == scrubbed + + +def test_scrub_request_text_keeps_no_copy_of_the_prompt_after_it_returns() -> None: + prompt: Final = "".join(f"secret {index} " for index in range(20_000)) + error: Final = f"Invalid content: '{prompt}'" + already_tracing: Final = tracemalloc.is_tracing() + if not already_tracing: + tracemalloc.start() + baseline, _ = tracemalloc.get_traced_memory() + try: + scrubbed: Final = scrub_request_text(error, request_texts(prompt)) + kept, _ = tracemalloc.get_traced_memory() + finally: + if not already_tracing: + tracemalloc.stop() + + assert scrubbed == "Invalid content: 'redacted-by-litellm'" + assert kept - baseline < len(prompt) // 2, f"scrubbing kept {kept - baseline} bytes alive after returning" + + def test_scrub_request_text_replaces_the_whole_text_when_the_search_is_too_large() -> None: texts: Final = request_texts([f"message number {index}" for index in range(5_000)]) @@ -2572,6 +2639,76 @@ def test_scrubbed_exception_text_reads_the_message_off_the_traceback_without_a_l ) +class _ProviderError(Exception): + pass + + +def _raise_chained(chain: tuple[BaseException, ...]) -> None: + """Raise the last of ``chain`` while handling the one before it, and so on down to the first.""" + if len(chain) == 1: + raise chain[0] + try: + _raise_chained(chain[:-1]) + except BaseException as earlier: + raise chain[-1] from earlier + + +def _raised(chain: tuple[BaseException, ...]) -> BaseException: + with pytest.raises(type(chain[-1])) as raised: + _raise_chained(chain) + return raised.value + + +def _failure(exception: BaseException, error_information: Mapping[str, str]) -> dict[str, object]: + return {"exception": exception, "standard_logging_object": {"error_information": error_information}} + + +SCRUBBED_ERROR: Final = {"error_message": "bad: redacted-by-litellm", "traceback": ""} + + +def test_scrubbed_exception_record_prints_the_exceptions_own_frames_without_a_logged_traceback() -> None: + exception: Final = _raised( + (ValueError("redacted-by-litellm"), KeyError("redacted-by-litellm"), _ProviderError("bad: redacted-by-litellm")) + ) + printed: Final = "".join(traceback.format_exception(exception)) + scrubbed: Final = scrubbed_exception_record(_failure(exception, SCRUBBED_ERROR)) + + assert scrubbed == ( + "bad: redacted-by-litellm", + printed.replace("KeyError: 'redacted-by-litellm'", "KeyError: redacted-by-litellm"), + ) + assert scrubbed is not None and "in _raise_chained" in scrubbed[1] + + +def test_scrubbed_exception_record_replaces_the_text_of_each_exception_the_failure_chains() -> None: + exception: Final = _raised((ValueError(PROMPT), _ProviderError("bad: redacted-by-litellm"))) + scrubbed: Final = scrubbed_exception_record(_failure(exception, SCRUBBED_ERROR)) + + assert scrubbed is not None and "123-45-6789" not in scrubbed[1] + assert "ValueError: redacted-by-litellm\n\nThe above exception was the direct cause" in scrubbed[1] + assert scrubbed[1].endswith("_ProviderError: bad: redacted-by-litellm\n") + + +def test_scrubbed_exception_record_stops_at_an_exception_chained_back_to_itself() -> None: + first: Final = ValueError("redacted-by-litellm") + second: Final = _ProviderError("bad: redacted-by-litellm") + first.__context__ = second + second.__context__ = first + + assert scrubbed_exception_record(_failure(second, SCRUBBED_ERROR)) == ( + "bad: redacted-by-litellm", + "".join(traceback.format_exception(second)), + ) + + +def test_scrubbed_exception_record_keeps_a_logged_traceback_and_skips_an_unscrubbed_error() -> None: + exception: Final = _raised((_ProviderError(f"bad: {PROMPT}"),)) + logged: Final = {"error_message": "bad: redacted-by-litellm", "traceback": "tb redacted-by-litellm"} + + assert scrubbed_exception_record(_failure(exception, logged)) == (logged["error_message"], logged["traceback"]) + assert scrubbed_exception_record(_failure(exception, {"error_message": "bad", "traceback": ""})) is None + + def test_scrubbed_error_information_for_request_scrubs_only_when_the_request_redacts() -> None: error_information: Final = StandardLoggingPayloadErrorInformation( error_code="400", error_class="BadRequestError", error_message=f"bad: {PROMPT}", traceback=f"tb {PROMPT}" From 1c67f492c3c97e16aaa2ee054ba8d24e1cbd63aa Mon Sep 17 00:00:00 2001 From: yucheng Date: Wed, 4 Nov 2026 19:17:15 -0800 Subject: [PATCH 7/9] feat(logging): name the request texts a failure's error quotes --- litellm/litellm_core_utils/redact_messages.py | 10 ++++++++++ .../test_redact_messages.py | 19 +++++++++++++++++++ 2 files changed, 29 insertions(+) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index ace55b53dfc..d8473468465 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -514,6 +514,16 @@ def scrub_request_text(text: str, texts: Collection[str]) -> str: return REDACTED_BY_LITELLM if scrubbed is None else scrubbed +def quoted_request_texts(text: str, texts: Collection[str]) -> frozenset[str]: + """ + The request ``texts`` that ``scrub_request_text`` acts on in ``text``: those it quotes, or all of them when + ``text`` holds a pydantic ``input_value`` or is too large to search one text at a time. + """ + if len(text) * len(texts) > _MAX_SCRUB_COMPARISONS: + return frozenset(texts) + return frozenset(each for each in texts if scrub_request_text(text, (each,)) != text) + + def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str | None: """ ``text`` with each quote of ``echoes`` replaced by ``REDACTED_BY_LITELLM`` in one left-to-right pass, the diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index 07b300d94ea..8ccf73e1066 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -32,6 +32,7 @@ from litellm.litellm_core_utils.redact_messages import ( _redact_responses_api_output, _redacted_responses_api_response, perform_redaction, + quoted_request_texts, redacted_model_call_details_for_custom_logger, redacted_response_obj_for_custom_logger, redacted_standard_logging_payload, @@ -2493,6 +2494,24 @@ def test_scrub_request_text_replaces_the_whole_text_when_the_prompt_repeats_past assert scrub_request_text("bad: secret " * echoes, request_texts("secret")) == scrubbed +@pytest.mark.parametrize( + ("error", "quoted"), + [ + ("Invalid content: 'secret one' and \"tab\\tafter\"", {"secret one", "tab\tafter"}), + ("litellm.RateLimitError: Rate limit reached", set()), + ("1 validation error\n Input should be a valid string [input_value='cut...', input_type=str]", None), + ("x" * 5_000, None), + ], + ids=["quoted_verbatim_or_escaped", "quoted_only_inside_a_word", "pydantic_input_value", "too_large_to_search"], +) +def test_quoted_request_texts_names_the_texts_a_scrub_of_the_error_acts_on(error: str, quoted: set[str] | None) -> None: + texts: Final = request_texts( + "secret one", "tab\tafter", "Error", [f"message number {index}" for index in range(2_000)] + ) + + assert quoted_request_texts(error, texts) == (texts if quoted is None else quoted) + + def test_scrub_request_text_keeps_no_copy_of_the_prompt_after_it_returns() -> None: prompt: Final = "".join(f"secret {index} " for index in range(20_000)) error: Final = f"Invalid content: '{prompt}'" From 5a47a6b49950e1cd20f45bfd15eb59964444eef7 Mon Sep 17 00:00:00 2001 From: yucheng Date: Wed, 4 Nov 2026 19:39:56 -0800 Subject: [PATCH 8/9] fix(logging): keep whole-word matching to one-word request text, and count a neighbouring echo, escape, label or marker as a break --- litellm/litellm_core_utils/redact_messages.py | 52 +++++++++++++------ .../test_redact_messages.py | 31 +++++++++++ 2 files changed, 67 insertions(+), 16 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index d8473468465..778936b9c88 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -527,8 +527,9 @@ def quoted_request_texts(text: str, texts: Collection[str]) -> frozenset[str]: def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str | None: """ ``text`` with each quote of ``echoes`` replaced by ``REDACTED_BY_LITELLM`` in one left-to-right pass, the - longest where several start at one place. ``None`` when ``echoes`` turn up more often than a failure path - should look through. + longest where several start at one place. An echo that is a single word only counts where it stands as its own + word, so a prompt such as ``Error`` leaves ``RateLimitError`` alone. ``None`` when ``echoes`` turn up more often + than a failure path should look through. """ found: Final = tuple( itertools.islice( @@ -537,7 +538,17 @@ def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str | None: ) if len(found) > _MAX_ECHO_OCCURRENCES: return None - ends: Final = dict(sorted((span for span in found if _stands_alone(text, *span)), key=lambda span: span[1])) + echo_starts: Final = frozenset(start for start, _, _ in found) + echo_ends: Final = frozenset(end for _, end, _ in found) + counted: Final = ( + (start, end) + for start, end, single_word in found + if not single_word + or ( + (start in echo_ends or _is_break_before(text, start)) and (end in echo_starts or _is_break_after(text, end)) + ) + ) + ends: Final = dict(sorted(counted, key=lambda span: span[1])) starts: Final = sorted(ends) frontiers: Final = itertools.accumulate(starts, functools.partial(_frontier_after, ends), initial=0) chosen: Final = tuple(start for start, frontier in zip(starts, frontiers) if start >= frontier) @@ -554,15 +565,16 @@ def _frontier_after(ends: Mapping[int, int], frontier: int, start: int) -> int: return ends[start] if start >= frontier else frontier -def _quote_spans(text: str, form: str) -> Iterator[tuple[int, int]]: - """Where each quote of ``form`` in ``text`` starts and ends, overlaps included. A form short enough to occur in - ordinary wording only counts between quotes.""" +def _quote_spans(text: str, form: str) -> Iterator[tuple[int, int, bool]]: + """Where each quote of ``form`` in ``text`` starts and ends, overlaps included, and whether ``form`` is a single + word. A form short enough to occur in ordinary wording only counts between quotes.""" if len(form) >= _MIN_UNQUOTED_TEXT_LENGTH: - return ((start, start + len(form)) for start in _found(text, form)) + single_word: Final = form.isascii() and form.replace("_", "").isalnum() + return ((start, start + len(form), single_word) for start in _found(text, form)) quoted_starts: Final = itertools.chain.from_iterable( _found(text, f"{opening}{form}{closing}") for opening, closing in itertools.product(_QUOTES, repeat=2) ) - return ((start + 1, start + 1 + len(form)) for start in quoted_starts) + return ((start + 1, start + 1 + len(form), False) for start in quoted_starts) def _found(text: str, piece: str) -> Iterator[int]: @@ -575,21 +587,29 @@ def _found(text: str, piece: str) -> Iterator[int]: ) -def _stands_alone(text: str, start: int, end: int) -> bool: - """Whether ``text[start:end]`` is not part of a longer word. An escape such as ``\\n`` before it counts as a break.""" - return (not _is_word_character(text[start]) or _is_word_break(text, start)) and ( - not _is_word_character(text[end - 1]) or end == len(text) or not _is_word_character(text[end]) - ) - - -def _is_word_break(text: str, index: int) -> bool: +def _is_break_before(text: str, index: int) -> bool: + """ + Whether a word starts at ``index`` of ``text``. An escape such as ``\\n`` before it and a ``REDACTED_BY_LITELLM`` + an earlier pass put there count as breaks. + """ return ( index == 0 or not _is_word_character(text[index - 1]) + or text.endswith(REDACTED_BY_LITELLM, 0, index) or _ESCAPE_TAIL.search(text, max(0, index - 10), index) is not None ) +def _is_break_after(text: str, index: int) -> bool: + """Whether a word ends at ``index`` of ``text``. A pydantic ``input_value=`` or a ``REDACTED_BY_LITELLM`` right + after it counts as a break.""" + return ( + index == len(text) + or not _is_word_character(text[index]) + or text.startswith((_INPUT_VALUE_LABEL, REDACTED_BY_LITELLM), index) + ) + + def _is_word_character(character: str) -> bool: return character.isascii() and (character.isalnum() or character == "_") diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index 8ccf73e1066..b3a1ca6936a 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -2477,6 +2477,37 @@ def test_scrub_request_text_replaces_a_prompt_that_stands_as_its_own_word(error: assert scrub_request_text(error, request_texts("Error")) == scrubbed +@pytest.mark.parametrize( + ("texts", "error", "scrubbed"), + [ + ( + ("my ssn is 1234",), + "litellm.BadRequestErrormy ssn is 1234Error", + "litellm.BadRequestErrorredacted-by-litellmError", + ), + (("Hello", "world"), "content: Helloworld!", "content: redacted-by-litellmredacted-by-litellm!"), + ( + ("secretinput_value=",), + "bad: secretinput_value=x", + "bad: redacted-by-litellminput_value=redacted-by-litellm", + ), + (("Firstinput_value=1", "Second"), "x: Firstinput_value=1Second", "x: redacted-by-litellmredacted-by-litellm"), + (("Firstinput_value=1", "Second"), "x: SecondFirstinput_value=1", "x: redacted-by-litellmredacted-by-litellm"), + ], + ids=[ + "several_words_inside_a_word", + "next_to_another_text", + "before_its_own_input_value_label", + "after_an_earlier_replacement", + "before_an_earlier_replacement", + ], +) +def test_scrub_request_text_replaces_a_prompt_glued_to_other_text_when_it_is_not_one_word( + texts: tuple[str, ...], error: str, scrubbed: str +) -> None: + assert scrub_request_text(error, request_texts(*texts)) == scrubbed + + def test_scrub_request_text_replaces_the_longest_prompt_that_starts_at_one_place() -> None: scrubbed: Final = scrub_request_text("bad: secret code list", request_texts("secret", "secret code", "code list")) From 85067355f5efc76164cd9a168e00cc9961d9b8cf Mon Sep 17 00:00:00 2001 From: yucheng Date: Thu, 5 Nov 2026 01:05:40 -0800 Subject: [PATCH 9/9] fix(logging): name every request text a scrub needs, even one glued into a word, and print chained exceptions without recursion --- litellm/litellm_core_utils/redact_messages.py | 69 ++++++++++++------- .../test_redact_messages.py | 37 ++++++++-- 2 files changed, 77 insertions(+), 29 deletions(-) diff --git a/litellm/litellm_core_utils/redact_messages.py b/litellm/litellm_core_utils/redact_messages.py index 778936b9c88..e0fa349b42b 100644 --- a/litellm/litellm_core_utils/redact_messages.py +++ b/litellm/litellm_core_utils/redact_messages.py @@ -495,13 +495,8 @@ def scrub_request_text(text: str, texts: Collection[str]) -> str: return text if len(text) * len(texts) > _MAX_SCRUB_COMPARISONS: return REDACTED_BY_LITELLM - forms: Final = frozenset( - itertools.chain.from_iterable(_echo_forms(each) for each in texts if len(each) <= len(text)) - ) echoes: Final = sorted( - (form for form in (each.removesuffix(_INPUT_VALUE_LABEL) for each in forms) if form and form in text), - key=len, - reverse=True, + frozenset(itertools.chain.from_iterable(_quotes_in(text, each) for each in texts)), key=len, reverse=True ) label_quotes: Final = tuple(form for form in echoes if _INPUT_VALUE_LABEL in form) other_quotes: Final = tuple(form for form in echoes if _INPUT_VALUE_LABEL not in form) @@ -516,12 +511,24 @@ def scrub_request_text(text: str, texts: Collection[str]) -> str: def quoted_request_texts(text: str, texts: Collection[str]) -> frozenset[str]: """ - The request ``texts`` that ``scrub_request_text`` acts on in ``text``: those it quotes, or all of them when - ``text`` holds a pydantic ``input_value`` or is too large to search one text at a time. + The request ``texts`` that ``scrub_request_text`` needs to scrub ``text`` as it would with all of them: those + quoted anywhere in it, even inside a word, or all of them when ``text`` holds a pydantic ``input_value`` or is + too large to search. """ - if len(text) * len(texts) > _MAX_SCRUB_COMPARISONS: + if _INPUT_VALUE_LABEL in text or len(text) * len(texts) > _MAX_SCRUB_COMPARISONS: return frozenset(texts) - return frozenset(each for each in texts if scrub_request_text(text, (each,)) != text) + return frozenset(each for each in texts if _quotes_in(text, each)) + + +def _quotes_in(text: str, quoted: str) -> tuple[str, ...]: + """The forms of ``quoted`` that turn up in ``text``, each without a trailing ``input_value=``.""" + if len(quoted) > len(text): + return () + return tuple( + form + for form in (each.removesuffix(_INPUT_VALUE_LABEL) for each in _echo_forms(quoted)) + if form and form in text + ) def _with_echoes_replaced(text: str, echoes: Collection[str]) -> str | None: @@ -698,29 +705,43 @@ def scrubbed_exception_record(model_call_details: Mapping[str, object]) -> tuple exception: Final = model_call_details.get("exception") if scrubbed is None or scrubbed[1] or not isinstance(exception, BaseException): return scrubbed - return scrubbed[0], _exception_stack(exception, scrubbed[0], frozenset()) + chain: Final = _exception_chain(exception) + earlier: Final = "".join( + _exception_frames(older, REDACTED_BY_LITELLM) + + (_DIRECT_CAUSE_LINE if newer.__cause__ is not None else _CONTEXT_LINE) + for newer, older in reversed(tuple(itertools.pairwise(chain))) + ) + return scrubbed[0], earlier + _exception_frames(exception, scrubbed[0]) -def _exception_stack(exception: BaseException, message: str, newer: frozenset[int]) -> str: - """``exception``'s traceback as Python prints it, with ``message`` for its text and ``REDACTED_BY_LITELLM`` for - the text of each exception it chains. ``newer`` holds the exceptions already printed after it.""" - printed: Final = newer | {id(exception)} - caused: Final = exception.__cause__ is not None - chained: Final = ( - exception.__cause__ if caused else None if exception.__suppress_context__ else exception.__context__ - ) - earlier: Final = ( - "" - if chained is None or id(chained) in printed - else _exception_stack(chained, REDACTED_BY_LITELLM, printed) + (_DIRECT_CAUSE_LINE if caused else _CONTEXT_LINE) +def _exception_chain(exception: BaseException) -> tuple[BaseException, ...]: + """``exception`` and each exception it chains as Python prints them, newest first, up to one already in it.""" + walk: Final = itertools.accumulate(itertools.repeat(None), _with_older_exception, initial=(exception,)) + return next(chain for chain, longer in itertools.pairwise(walk) if longer is chain) + + +def _with_older_exception(chain: tuple[BaseException, ...], _: None) -> tuple[BaseException, ...]: + """``chain`` with the exception its oldest one chains added, unless there is none or ``chain`` holds it.""" + oldest: Final = chain[-1] + older: Final = ( + oldest.__cause__ + if oldest.__cause__ is not None + else None + if oldest.__suppress_context__ + else oldest.__context__ ) + return chain if older is None or any(older is each for each in chain) else (*chain, older) + + +def _exception_frames(exception: BaseException, message: str) -> str: + """``exception``'s own frames and last line as Python prints them, with ``message`` for its text.""" frames: Final = "".join(traceback.format_tb(exception.__traceback__)) header: Final = "Traceback (most recent call last):\n" if frames else "" kind: Final = type(exception) name: Final = ( kind.__qualname__ if kind.__module__ in ("__main__", "builtins") else f"{kind.__module__}.{kind.__qualname__}" ) - return f"{earlier}{header}{frames}{name}: {message}\n" if message else f"{earlier}{header}{frames}{name}\n" + return f"{header}{frames}{name}: {message}\n" if message else f"{header}{frames}{name}\n" def _exception_text(traceback_text: str) -> str: diff --git a/tests/unit/litellm_core_utils/test_redact_messages.py b/tests/unit/litellm_core_utils/test_redact_messages.py index b3a1ca6936a..72bc55e35f9 100644 --- a/tests/unit/litellm_core_utils/test_redact_messages.py +++ b/tests/unit/litellm_core_utils/test_redact_messages.py @@ -8,8 +8,10 @@ but litellm_params["litellm_metadata"] is None. import asyncio import copy import importlib +import itertools import json import os +import sys import threading import traceback import tracemalloc @@ -2529,18 +2531,29 @@ def test_scrub_request_text_replaces_the_whole_text_when_the_prompt_repeats_past ("error", "quoted"), [ ("Invalid content: 'secret one' and \"tab\\tafter\"", {"secret one", "tab\tafter"}), - ("litellm.RateLimitError: Rate limit reached", set()), + ("Connection timed out", set()), + ("litellm.RateLimitError: Rate limit reached", {"Error"}), + ("Invalid content: Helloworld!", {"Hello", "world"}), ("1 validation error\n Input should be a valid string [input_value='cut...', input_type=str]", None), ("x" * 5_000, None), ], - ids=["quoted_verbatim_or_escaped", "quoted_only_inside_a_word", "pydantic_input_value", "too_large_to_search"], + ids=[ + "quoted_verbatim_or_escaped", + "quotes_none", + "quoted_inside_a_word", + "message_parts_joined_into_one_word", + "pydantic_input_value", + "too_large_to_search", + ], ) -def test_quoted_request_texts_names_the_texts_a_scrub_of_the_error_acts_on(error: str, quoted: set[str] | None) -> None: +def test_quoted_request_texts_names_the_texts_a_scrub_of_the_error_needs(error: str, quoted: set[str] | None) -> None: texts: Final = request_texts( - "secret one", "tab\tafter", "Error", [f"message number {index}" for index in range(2_000)] + "secret one", "tab\tafter", "Error", "Hello", "world", [f"message number {index}" for index in range(2_000)] ) + named: Final = quoted_request_texts(error, texts) - assert quoted_request_texts(error, texts) == (texts if quoted is None else quoted) + assert named == (texts if quoted is None else quoted) + assert scrub_request_text(error, named) == scrub_request_text(error, texts) def test_scrub_request_text_keeps_no_copy_of_the_prompt_after_it_returns() -> None: @@ -2751,6 +2764,20 @@ def test_scrubbed_exception_record_stops_at_an_exception_chained_back_to_itself( ) +def test_scrubbed_exception_record_prints_a_chain_longer_than_the_recursion_limit() -> None: + chain: Final = ( + _ProviderError("bad: redacted-by-litellm"), + *(ValueError("redacted-by-litellm") for _ in range(sys.getrecursionlimit())), + ) + for newer, older in itertools.pairwise(chain): + newer.__cause__ = older + + assert scrubbed_exception_record(_failure(chain[0], SCRUBBED_ERROR)) == ( + "bad: redacted-by-litellm", + "".join(traceback.format_exception(chain[0])), + ) + + def test_scrubbed_exception_record_keeps_a_logged_traceback_and_skips_an_unscrubbed_error() -> None: exception: Final = _raised((_ProviderError(f"bad: {PROMPT}"),)) logged: Final = {"error_message": "bad: redacted-by-litellm", "traceback": "tb redacted-by-litellm"}