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

@@ -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:

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"}