From 5ddb335a3152e761408cbfc853879c715740e64c Mon Sep 17 00:00:00 2001 From: Ryan Crabbe Date: Tue, 10 Feb 2026 14:53:47 -0800 Subject: [PATCH] perf: shallow copy messages in Logging.__init__ (3.4x faster) Replace copy.deepcopy(messages) with shallow dict copy. Safe because proxy's update_messages() overwrites self.messages before reads, and no code mutates nested message objects in-place. --- litellm/litellm_core_utils/litellm_logging.py | 6 +- .../test_litellm_logging.py | 288 ++++++++++++++++++ 2 files changed, 293 insertions(+), 1 deletion(-) diff --git a/litellm/litellm_core_utils/litellm_logging.py b/litellm/litellm_core_utils/litellm_logging.py index 7ae62718af0..a443425c4c3 100644 --- a/litellm/litellm_core_utils/litellm_logging.py +++ b/litellm/litellm_core_utils/litellm_logging.py @@ -334,7 +334,11 @@ class Logging(LiteLLMLoggingBaseClass): messages = new_messages self.model = model - self.messages = copy.deepcopy(messages) if messages is not None else None + self.messages = ( + [msg.copy() if isinstance(msg, dict) else msg for msg in messages] + if isinstance(messages, list) + else messages + ) if messages is not None else None self.stream = stream self.start_time = start_time # log the call start time self.call_type = call_type diff --git a/tests/test_litellm/litellm_core_utils/test_litellm_logging.py b/tests/test_litellm/litellm_core_utils/test_litellm_logging.py index 734d52918ba..73d220f0e1d 100644 --- a/tests/test_litellm/litellm_core_utils/test_litellm_logging.py +++ b/tests/test_litellm/litellm_core_utils/test_litellm_logging.py @@ -1355,3 +1355,291 @@ def test_get_error_information_error_code_priority(): result = StandardLoggingPayloadSetup.get_error_information(no_code_exception) assert result["error_code"] == "" assert result["error_class"] == "NoCodeException" + + +# ────────────────────────────────────────────────────────────────────── +# Tests for _get_assembled_streaming_response non-streaming early return +# ────────────────────────────────────────────────────────────────────── + + +def _make_logging_obj(stream: bool) -> LitellmLogging: + return LitellmLogging( + model="openai/codex-mini-latest", + messages=[{"role": "user", "content": "Hey"}], + stream=stream, + call_type="completion", + start_time=time.time(), + litellm_call_id="test-123", + function_id="test-fn", + ) + + +def test_get_assembled_streaming_response_returns_none_for_non_streaming(): + """Non-streaming requests should return None so the streaming block is skipped.""" + import datetime + + logging_obj = _make_logging_obj(stream=False) + result = ModelResponse(id="resp-1", choices=[], model="test") + assembled = logging_obj._get_assembled_streaming_response( + result=result, + start_time=datetime.datetime.now(), + end_time=datetime.datetime.now(), + is_async=True, + streaming_chunks=[], + ) + assert assembled is None + + +def test_get_assembled_streaming_response_returns_result_for_streaming(): + """Streaming requests should return the ModelResponse for further processing.""" + import datetime + + logging_obj = _make_logging_obj(stream=True) + result = ModelResponse(id="resp-1", choices=[], model="test") + assembled = logging_obj._get_assembled_streaming_response( + result=result, + start_time=datetime.datetime.now(), + end_time=datetime.datetime.now(), + is_async=True, + streaming_chunks=[], + ) + assert assembled is result + + +def test_get_assembled_streaming_response_returns_none_for_non_streaming_text_completion(): + """Non-streaming TextCompletionResponse should also return None.""" + import datetime + + logging_obj = _make_logging_obj(stream=False) + result = TextCompletionResponse(id="resp-1", choices=[], model="test") + assembled = logging_obj._get_assembled_streaming_response( + result=result, + start_time=datetime.datetime.now(), + end_time=datetime.datetime.now(), + is_async=True, + streaming_chunks=[], + ) + assert assembled is None + + +@pytest.mark.asyncio +async def test_non_streaming_computes_standard_logging_object_once(): + """ + Non-streaming acompletion should call get_standard_logging_object_payload + exactly once, not twice. + """ + import asyncio + + import litellm + + with patch.object( + litellm.litellm_core_utils.litellm_logging, + "get_standard_logging_object_payload", + ) as mock_payload: + await litellm.acompletion( + max_tokens=100, + messages=[{"role": "user", "content": "Hey"}], + model="openai/codex-mini-latest", + mock_response="Hello, world!", + ) + await asyncio.sleep(1) + assert mock_payload.call_count == 1 + + +@pytest.mark.asyncio +async def test_emit_standard_logging_payload_called_for_non_streaming(): + """ + emit_standard_logging_payload should still be called for non-streaming + requests (moved from the streaming block to _process_hidden_params_and_response_cost). + """ + import asyncio + + import litellm + + with patch.object( + litellm.litellm_core_utils.litellm_logging, + "emit_standard_logging_payload", + ) as mock_emit: + await litellm.acompletion( + max_tokens=100, + messages=[{"role": "user", "content": "Hey"}], + model="openai/codex-mini-latest", + mock_response="Hello, world!", + ) + await asyncio.sleep(1) + assert mock_emit.call_count >= 1 + + +class TestShouldRunCallbackEnterpriseGuard: + """ + Tests for the early-out guard in should_run_callback() that skips + EnterpriseCallbackControls.is_callback_disabled_dynamically() when + no dynamic callback disabling is configured. + """ + + @pytest.fixture + def logging_obj_for_callback(self): + return LitellmLogging( + model="gpt-4o-mini", + messages=[{"role": "user", "content": "Hey"}], + stream=False, + call_type="acompletion", + start_time=time.time(), + litellm_call_id="test-callback-guard", + function_id="test-fn", + ) + + def test_skips_enterprise_call_when_no_disabling_configured(self, logging_obj_for_callback): + """ + When neither litellm_disabled_callbacks nor x-litellm-disable-callbacks + header is set, should_run_callback should NOT call the enterprise function. + """ + litellm_params = {"proxy_server_request": {"headers": {}}} + + with patch( + "litellm.litellm_core_utils.litellm_logging.EnterpriseCallbackControls" + ) as mock_enterprise: + mock_enterprise.__bool__ = lambda self: True + result = logging_obj_for_callback.should_run_callback( + callback="langfuse", + litellm_params=litellm_params, + event_hook="success_handler", + ) + assert result is True + mock_enterprise.is_callback_disabled_dynamically.assert_not_called() + + def test_calls_enterprise_when_header_is_set(self, logging_obj_for_callback): + """ + When the x-litellm-disable-callbacks header is set, should_run_callback + should call the enterprise function. + """ + litellm_params = { + "proxy_server_request": { + "headers": {"x-litellm-disable-callbacks": "langfuse"} + } + } + + with patch( + "litellm.litellm_core_utils.litellm_logging.EnterpriseCallbackControls" + ) as mock_enterprise: + mock_enterprise.__bool__ = lambda self: True + mock_enterprise.is_callback_disabled_dynamically.return_value = True + result = logging_obj_for_callback.should_run_callback( + callback="langfuse", + litellm_params=litellm_params, + event_hook="success_handler", + ) + assert result is False + mock_enterprise.is_callback_disabled_dynamically.assert_called_once() + + def test_calls_enterprise_when_dynamic_params_set(self, logging_obj_for_callback): + """ + When litellm_disabled_callbacks is set in standard_callback_dynamic_params, + should_run_callback should call the enterprise function. + """ + from litellm.types.utils import StandardCallbackDynamicParams + + logging_obj_for_callback.standard_callback_dynamic_params = StandardCallbackDynamicParams( + litellm_disabled_callbacks=["langfuse"] + ) + litellm_params = {"proxy_server_request": {"headers": {}}} + + with patch( + "litellm.litellm_core_utils.litellm_logging.EnterpriseCallbackControls" + ) as mock_enterprise: + mock_enterprise.__bool__ = lambda self: True + mock_enterprise.is_callback_disabled_dynamically.return_value = True + result = logging_obj_for_callback.should_run_callback( + callback="langfuse", + litellm_params=litellm_params, + event_hook="success_handler", + ) + assert result is False + mock_enterprise.is_callback_disabled_dynamically.assert_called_once() + + def test_returns_true_when_enterprise_says_not_disabled(self, logging_obj_for_callback): + """ + When the header is set but the enterprise function says the callback + is NOT disabled, should_run_callback should return True. + """ + litellm_params = { + "proxy_server_request": { + "headers": {"x-litellm-disable-callbacks": "datadog"} + } + } + + with patch( + "litellm.litellm_core_utils.litellm_logging.EnterpriseCallbackControls" + ) as mock_enterprise: + mock_enterprise.__bool__ = lambda self: True + mock_enterprise.is_callback_disabled_dynamically.return_value = False + result = logging_obj_for_callback.should_run_callback( + callback="langfuse", + litellm_params=litellm_params, + event_hook="success_handler", + ) + assert result is True + + +def test_logging_messages_isolated_from_original_string_content(): + """ + Mutating the original message dict's 'content' (string) after Logging.__init__ + must not affect the copy stored on the logging object. + """ + messages = [{"role": "user", "content": "hello"}] + logging_obj = LitellmLogging( + model="gpt-4", + messages=messages, + stream=False, + call_type="completion", + start_time=time.time(), + litellm_call_id="12345", + function_id="1245", + ) + # Mutate the original dict + messages[0]["content"] = "CHANGED" + assert logging_obj.messages[0]["content"] == "hello" + + +def test_logging_messages_isolated_from_original_list_content(): + """ + Reassigning the original message dict's 'content' (list of parts) after + Logging.__init__ must not affect the copy stored on the logging object. + """ + original_content = [{"type": "text", "text": "hello"}] + messages = [{"role": "user", "content": original_content}] + logging_obj = LitellmLogging( + model="gpt-4", + messages=messages, + stream=False, + call_type="completion", + start_time=time.time(), + litellm_call_id="12345", + function_id="1245", + ) + # Reassign content on the original dict — shallow copy protects against this + messages[0]["content"] = [{"type": "text", "text": "CHANGED"}] + assert logging_obj.messages[0]["content"] == original_content + + +def test_logging_messages_isolated_tool_calls(): + """ + Reassigning 'tool_calls' on the original message dict after Logging.__init__ + must not affect the copy stored on the logging object. + """ + original_tool_calls = [ + {"id": "call_1", "type": "function", "function": {"name": "get_weather", "arguments": "{}"}} + ] + messages = [{"role": "assistant", "tool_calls": original_tool_calls}] + logging_obj = LitellmLogging( + model="gpt-4", + messages=messages, + stream=False, + call_type="completion", + start_time=time.time(), + litellm_call_id="12345", + function_id="1245", + ) + # Reassign tool_calls on the original dict + messages[0]["tool_calls"] = [{"id": "call_NEW", "type": "function", "function": {"name": "other", "arguments": "{}"}}] + assert logging_obj.messages[0]["tool_calls"] == original_tool_calls