From a32854a516e2f2a1609ff98950fd7f4b9b788be2 Mon Sep 17 00:00:00 2001 From: yucheng Date: Fri, 30 Oct 2026 18:39:22 -0700 Subject: [PATCH] fix(logging): scrub the prompt out of SDK failure logs when message logging is redacted --- litellm/integrations/mlflow.py | 18 ++- litellm/integrations/opentelemetry.py | 9 +- litellm/litellm_core_utils/litellm_logging.py | 30 +++- tests/unit/integrations/test_mlflow.py | 51 +++++++ tests/unit/integrations/test_opentelemetry.py | 36 +++++ .../test_litellm_logging.py | 130 ++++++++++++++++++ 6 files changed, 265 insertions(+), 9 deletions(-) diff --git a/litellm/integrations/mlflow.py b/litellm/integrations/mlflow.py index 8731e96440f..b338567d248 100644 --- a/litellm/integrations/mlflow.py +++ b/litellm/integrations/mlflow.py @@ -1,9 +1,11 @@ import json import threading +from collections.abc import Mapping from typing import TYPE_CHECKING, Any, Final from litellm._logging import verbose_logger from litellm.integrations.custom_logger import CustomLogger +from litellm.litellm_core_utils.redact_messages import scrubbed_exception_text if TYPE_CHECKING: from litellm.types.utils import StandardLoggingPayload @@ -74,7 +76,7 @@ class MlflowLogger(CustomLogger): async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time): self._handle_failure(kwargs, response_obj, start_time, end_time) - def _handle_failure(self, kwargs, response_obj, start_time, end_time): + def _handle_failure(self, kwargs: Mapping[str, object], response_obj, start_time, end_time): """ Log the failure event as an MLflow span. Note that this method is called *synchronously* unlike the success handler. @@ -88,7 +90,19 @@ class MlflowLogger(CustomLogger): # Record exception info as event if exception := kwargs.get("exception"): - span.add_event(SpanEvent.from_exception(exception)) + scrubbed: Final = scrubbed_exception_text(kwargs) + span.add_event( + SpanEvent.from_exception(exception) + if scrubbed is None + else SpanEvent( + name="exception", + attributes={ + "exception.message": scrubbed[0], + "exception.type": exception.__class__.__name__, + "exception.stacktrace": scrubbed[1], + }, + ) + ) self._extract_and_set_chat_attributes(span, kwargs, response_obj) self._end_span_or_trace( diff --git a/litellm/integrations/opentelemetry.py b/litellm/integrations/opentelemetry.py index a9bd93e6420..41ab1e98079 100644 --- a/litellm/integrations/opentelemetry.py +++ b/litellm/integrations/opentelemetry.py @@ -36,6 +36,7 @@ from litellm.integrations.otel.model.semconv import LiteLLM, Metric from litellm.integrations.otel.plumbing.otlp_tls import resolve_otlp_http_tls from litellm.integrations.otel.routing import routing_decision_attributes from litellm.litellm_core_utils.internal_call_metadata import is_unbilled_non_inference_call_from_params +from litellm.litellm_core_utils.redact_messages import scrubbed_exception_text from litellm.litellm_core_utils.safe_json_dumps import safe_dumps from litellm.litellm_core_utils.secret_redaction import redact_string from litellm.litellm_core_utils.service_tier_utils import ( @@ -2271,9 +2272,13 @@ class OpenTelemetry(OTELGenAISemconvMixin, CustomLogger): # Get the exception object if available exception: Final = kwargs.get("exception") + scrubbed: Final = scrubbed_exception_text(kwargs) - # Record the exception using OTEL's standard method - if exception is not None: + if exception is not None and scrubbed is not None: + span.record_exception( + exception, attributes={"exception.message": scrubbed[0], "exception.stacktrace": scrubbed[1]} + ) + elif exception is not None: span.record_exception(exception) # Get StandardLoggingPayload for structured error information diff --git a/litellm/litellm_core_utils/litellm_logging.py b/litellm/litellm_core_utils/litellm_logging.py index ce57a9bd4a5..57571b217f8 100644 --- a/litellm/litellm_core_utils/litellm_logging.py +++ b/litellm/litellm_core_utils/litellm_logging.py @@ -143,10 +143,15 @@ from litellm.litellm_core_utils.logging_utils import ( from litellm.litellm_core_utils.model_param_helper import ModelParamHelper from litellm.litellm_core_utils.ptu_pricing import is_spilled_over_ptu_request from litellm.litellm_core_utils.redact_messages import ( + failure_request_texts, redact_message_input_output_from_custom_logger, redact_message_input_output_from_logging, redacted_model_call_details_for_custom_logger, redacted_response_obj_for_custom_logger, + scrub_request_text, + scrubbed_error_fields, + scrubbed_exception_text, + should_redact_failure_logging, should_redact_message_logging, ) from litellm.litellm_core_utils.served_output_texts import ( @@ -4552,8 +4557,9 @@ class Logging(LiteLLMLoggingBaseClass): self.model_call_details["log_event_type"] = "failed_api_call" self.model_call_details["exception"] = exception + traceback_text: Final = redact_string(traceback_exception) if isinstance(traceback_exception, str) else None self.model_call_details["traceback_exception"] = ( - redact_string(traceback_exception) if isinstance(traceback_exception, str) else traceback_exception + traceback_exception if traceback_text is None else traceback_text ) self.model_call_details["end_time"] = end_time self.model_call_details.setdefault("original_response", None) @@ -4571,9 +4577,15 @@ class Logging(LiteLLMLoggingBaseClass): metadata: Final = self.model_call_details["litellm_params"].get("metadata", {}) or {} metadata.update(exception.headers) + # Building the payload redacts the messages in place, so read the request text first + redact: Final = should_redact_failure_logging(self.model_call_details) + request_texts: Final[frozenset[str]] = ( + failure_request_texts(self.model_call_details, getattr(self, "messages", None)) if redact else frozenset() + ) + ## STANDARDIZED LOGGING PAYLOAD - self.model_call_details["standard_logging_object"] = get_standard_logging_object_payload( + payload: Final = get_standard_logging_object_payload( kwargs=self.model_call_details, init_response_obj={}, start_time=start_time, @@ -4584,6 +4596,11 @@ class Logging(LiteLLMLoggingBaseClass): original_exception=exception, standard_built_in_tools_params=self.standard_built_in_tools_params, ) + self.model_call_details["standard_logging_object"] = ( + {**payload, **scrubbed_error_fields(payload, request_texts)} if redact and payload is not None else payload + ) + if redact and traceback_text is not None: + self.model_call_details["traceback_exception"] = scrub_request_text(traceback_text, request_texts) return start_time, end_time async def special_failure_handlers(self, exception: Exception): @@ -4679,6 +4696,9 @@ class Logging(LiteLLMLoggingBaseClass): ) ) self.mark_logging_complete(event_type="sync_failure") + scrubbed_exception: Final = scrubbed_exception_text(self.model_call_details) + logged_error: Final = str(exception) if scrubbed_exception is None else scrubbed_exception[0] + logged_traceback: Final = traceback_exception if scrubbed_exception is None else scrubbed_exception[1] for callback in callbacks: try: should_run = self.should_run_callback( @@ -4704,7 +4724,7 @@ class Logging(LiteLLMLoggingBaseClass): user_id=self._model_call_details_view.get("user", "default"), model=model, input=input, - error=traceback_exception, + error=logged_traceback, run_id=self.litellm_call_id, start_time=start_time, end_time=end_time, @@ -4771,7 +4791,7 @@ class Logging(LiteLLMLoggingBaseClass): end_time=end_time, response_obj=None, user_id=kwargs.get("user", None), - status_message=str(exception), + status_message=logged_error, level="ERROR", kwargs=kwargs, ) @@ -4790,7 +4810,7 @@ class Logging(LiteLLMLoggingBaseClass): response_obj=None, user_id=self.model_call_details.get("user", None), print_verbose=print_verbose, - status_message=str(exception), + status_message=logged_error, level="ERROR", kwargs=self.model_call_details, ) diff --git a/tests/unit/integrations/test_mlflow.py b/tests/unit/integrations/test_mlflow.py index 058d0ae885d..992bcaf6e5b 100644 --- a/tests/unit/integrations/test_mlflow.py +++ b/tests/unit/integrations/test_mlflow.py @@ -268,3 +268,54 @@ def test_mlflow_end_span_or_trace_works_with_mlflow_2x_client(): span=child_span, outputs="out", end_time_ns=1, status="OK" ) assert client.ended_spans == [("req-2", "span-2")] + + +class _ExceptionSpanEvent: + def __init__(self, name, attributes): + self.name = name + self.attributes = attributes + + @classmethod + def from_exception(cls, exception): + return cls( + "exception", + { + "exception.message": str(exception), + "exception.type": type(exception).__name__, + "exception.stacktrace": "raw", + }, + ) + + +@pytest.mark.parametrize("scrubbed", [True, False], ids=["scrubbed", "not_scrubbed"]) +def test_mlflow_failure_event_records_the_error_text_the_payload_logged(scrubbed): + secret = "my ssn is 123-45-6789" + modules = _mock_mlflow_modules() + modules["mlflow.entities"].SpanEvent = _ExceptionSpanEvent + with patch.dict("sys.modules", modules): + from litellm.integrations.mlflow import MlflowLogger + + mlflow_logger = MlflowLogger() + span = MagicMock() + mlflow_logger._start_span_or_trace = MagicMock(return_value=span) + mlflow_logger._end_span_or_trace = MagicMock() + mlflow_logger._extract_and_set_chat_attributes = MagicMock() + error_message = "bad input: redacted-by-litellm" if scrubbed else f"bad input: {secret}" + + mlflow_logger._handle_failure( + kwargs={ + "litellm_call_id": "x", + "exception": ValueError(f"bad input: {secret}"), + "standard_logging_object": { + "error_information": {"error_message": error_message, "traceback": "frames"} + }, + }, + response_obj=None, + start_time=datetime(2025, 1, 1), + end_time=datetime(2025, 1, 1), + ) + + event = span.add_event.call_args.args[0] + assert event.attributes["exception.type"] == "ValueError" + assert event.attributes["exception.message"] == error_message + assert event.attributes["exception.stacktrace"] == ("frames" if scrubbed else "raw") diff --git a/tests/unit/integrations/test_opentelemetry.py b/tests/unit/integrations/test_opentelemetry.py index 5f749e951b1..c8cc157611b 100644 --- a/tests/unit/integrations/test_opentelemetry.py +++ b/tests/unit/integrations/test_opentelemetry.py @@ -7636,3 +7636,39 @@ class TestOpentelemetryUnitTests: # Assert: error.message should be set from error_str using ErrorAttributes constant mock_span.set_attribute.assert_called_with(ErrorAttributes.ERROR_MESSAGE, "Fallback error message") + + +def test_record_exception_on_span_records_the_scrubbed_error_text_with_the_same_event_shape(): + from opentelemetry.sdk.trace import TracerProvider + from opentelemetry.sdk.trace.export import SimpleSpanProcessor + from opentelemetry.sdk.trace.export.in_memory_span_exporter import InMemorySpanExporter + + from litellm.integrations.opentelemetry import OpenTelemetry + + exporter = InMemorySpanExporter() + provider = TracerProvider() + provider.add_span_processor(SimpleSpanProcessor(exporter)) + secret = "my ssn is 123-45-6789" + exception = ValueError(f"bad input: {secret}") + + with provider.get_tracer(__name__).start_as_current_span("failure") as span: + OpenTelemetry()._record_exception_on_span( + span=span, + kwargs={ + "exception": exception, + "standard_logging_object": { + "error_information": { + "error_class": "ValueError", + "error_message": "bad input: redacted-by-litellm", + "traceback": "frames", + }, + }, + }, + ) + + (event,) = exporter.get_finished_spans()[0].events + assert secret not in str(dict(event.attributes)) + assert event.attributes["exception.message"] == "bad input: redacted-by-litellm" + assert event.attributes["exception.stacktrace"] == "frames" + assert event.attributes["exception.type"] == "ValueError" + assert event.attributes["exception.escaped"] == "False" diff --git a/tests/unit/litellm_core_utils/test_litellm_logging.py b/tests/unit/litellm_core_utils/test_litellm_logging.py index e8ea0c04f6f..62b0ce996b2 100644 --- a/tests/unit/litellm_core_utils/test_litellm_logging.py +++ b/tests/unit/litellm_core_utils/test_litellm_logging.py @@ -12049,6 +12049,136 @@ def test_uncached_price_keeps_an_earlier_price_failure(pr44187_priced_model: str assert logging_obj.model_call_details["response_cost_failure_debug_information"] == earlier_failure +SCRUB_PROMPT: Final = "my ssn is 123-45-6789" + + +class _FailureCapture(CustomLogger): + def __init__(self, **kwargs: bool) -> None: + super().__init__(**kwargs) + self.sync_kwargs: dict | None = None + self.async_kwargs: dict | None = None + + def log_failure_event(self, kwargs, response_obj, start_time, end_time): + self.sync_kwargs = kwargs + + async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time): + self.async_kwargs = kwargs + + +def _prompt_failure_logging_obj(litellm_params: Mapping[str, object] | None = None) -> LitellmLogging: + logging_obj: Final = LitellmLogging( + model="gpt-4o", + messages=[{"role": "user", "content": SCRUB_PROMPT}], + stream=False, + call_type="completion", + start_time=datetime.datetime(2025, 1, 1), + litellm_call_id="failure-scrub", + function_id="failure-scrub", + ) + logging_obj.model_call_details["messages"] = logging_obj.messages # as update_environment_variables sets it + if litellm_params is not None: + logging_obj.model_call_details["litellm_params"] = dict(litellm_params) + return logging_obj + + +def _prompt_echo_error() -> litellm.BadRequestError: + return litellm.BadRequestError( + message=f"Invalid message passed in {{'role': 'user', 'content': '{SCRUB_PROMPT}'}}", + model="gpt-4o", + llm_provider="openai", + ) + + +async def _async_failure_payload( + monkeypatch: pytest.MonkeyPatch, *, redact: bool, error: Exception, capture: _FailureCapture | None = None +) -> dict: + logger: Final = capture or _FailureCapture() + monkeypatch.setattr(litellm, "turn_off_message_logging", redact) + monkeypatch.setattr(litellm, "_async_failure_callback", [logger]) + await _prompt_failure_logging_obj().async_failure_handler(error, f"Traceback: {error}") + assert logger.async_kwargs is not None + return logger.async_kwargs + + +@pytest.mark.asyncio +async def test_failure_with_redaction_on_scrubs_the_prompt_out_of_the_error_and_keeps_the_rest(monkeypatch): + kwargs: Final = await _async_failure_payload(monkeypatch, redact=True, error=_prompt_echo_error()) + + payload: Final = kwargs["standard_logging_object"] + assert SCRUB_PROMPT not in json.dumps(payload, default=str) + assert SCRUB_PROMPT not in kwargs["traceback_exception"] + assert "Invalid message passed in" in payload["error_str"] + assert "'content': 'redacted-by-litellm'" in payload["error_information"]["error_message"] + assert payload["error_information"]["error_class"] == "BadRequestError" + assert payload["error_information"]["error_code"] == "400" + + +@pytest.mark.asyncio +async def test_failure_with_redaction_on_keeps_error_text_that_does_not_quote_the_prompt(monkeypatch): + error: Final = litellm.AuthenticationError( + message="Incorrect API key provided", model="gpt-4o", llm_provider="openai" + ) + + redacted: Final = (await _async_failure_payload(monkeypatch, redact=True, error=error))["standard_logging_object"] + raw: Final = (await _async_failure_payload(monkeypatch, redact=False, error=error))["standard_logging_object"] + + assert redacted["error_str"] == raw["error_str"] + assert redacted["error_information"] == raw["error_information"] + + +@pytest.mark.asyncio +async def test_failure_with_redaction_off_logs_the_error_as_raised(monkeypatch): + kwargs: Final = await _async_failure_payload(monkeypatch, redact=False, error=_prompt_echo_error()) + + assert SCRUB_PROMPT in kwargs["standard_logging_object"]["error_information"]["error_message"] + assert SCRUB_PROMPT in kwargs["traceback_exception"] + + +@pytest.mark.asyncio +@pytest.mark.parametrize("headers", [None, "x", ["a"]], ids=["none", "str", "list"]) +@pytest.mark.parametrize("redact", [True, False], ids=["redaction_on", "redaction_off"]) +async def test_failure_with_non_mapping_headers_is_still_logged(monkeypatch, headers, redact): + capture: Final = _FailureCapture() + monkeypatch.setattr(litellm, "turn_off_message_logging", redact) + monkeypatch.setattr(litellm, "_async_failure_callback", [capture]) + logging_obj: Final = _prompt_failure_logging_obj({"metadata": {"headers": headers}}) + + await logging_obj.async_failure_handler(_prompt_echo_error(), f"Traceback: {SCRUB_PROMPT}") + + assert capture.async_kwargs is not None + assert (SCRUB_PROMPT in capture.async_kwargs["traceback_exception"]) is not redact + + +def test_sync_failure_hands_callbacks_and_langfuse_the_scrubbed_error(monkeypatch): + capture: Final = _FailureCapture() + langfuse: Final = MagicMock() + monkeypatch.setattr(litellm, "turn_off_message_logging", True) + monkeypatch.setattr(litellm, "failure_callback", [capture, "langfuse"]) + monkeypatch.setattr(litellm_logging, "langFuseLogger", langfuse) + + _prompt_failure_logging_obj().failure_handler(_prompt_echo_error(), f"Traceback: {SCRUB_PROMPT}") + + assert capture.sync_kwargs is not None + assert SCRUB_PROMPT not in json.dumps(capture.sync_kwargs["standard_logging_object"], default=str) + status_message: Final = langfuse.log_event_on_langfuse.call_args.kwargs["status_message"] + assert "Invalid message passed in" in status_message + assert SCRUB_PROMPT not in status_message + + +def test_sync_failure_hands_lunary_the_scrubbed_traceback_when_only_the_traceback_quotes_the_prompt(monkeypatch): + lunary: Final = MagicMock() + monkeypatch.setattr(litellm, "turn_off_message_logging", True) + monkeypatch.setattr(litellm, "failure_callback", ["lunary"]) + monkeypatch.setattr(litellm_logging, "lunaryLogger", lunary) + error: Final = litellm.APIConnectionError(message="Connection failed", model="gpt-4o", llm_provider="openai") + + _prompt_failure_logging_obj().failure_handler(error, f"ValueError: bad input {SCRUB_PROMPT}\n\n{error}") + + logged_error: Final = lunary.log_event.call_args.kwargs["error"] + assert "ValueError: bad input redacted-by-litellm" in logged_error + assert SCRUB_PROMPT not in logged_error + + def test_enterprise_alerting_loggers_resolves_real_classes(): from litellm_enterprise.enterprise_callbacks.pagerduty.pagerduty import PagerDutyAlerting from litellm_enterprise.enterprise_callbacks.send_emails.resend_email import ResendEmailLogger