mirror of
https://github.com/BerriAI/litellm.git
synced 2026-09-07 08:26:10 +00:00
perf(logging): scan large base64 payloads for log truncation off the event loop (#39890)
* perf(logging): scan large base64 payloads for log truncation off the event loop Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> * perf(logging): make base64 offload threshold a plain constant Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> --------- Co-authored-by: yassin <yassin@berri.ai> Co-authored-by: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>
This commit is contained in:
parent
a0058ed157
commit
3c0900b7c5
5 changed files with 177 additions and 6 deletions
|
|
@ -89,6 +89,7 @@ LITELLM_MAX_STREAMING_DURATION_SECONDS: Final = (
|
|||
# Data URIs exceeding this are replaced with a size placeholder.
|
||||
# Set to 0 to disable truncation.
|
||||
MAX_BASE64_LENGTH_FOR_LOGGING: Final = int(os.getenv("MAX_BASE64_LENGTH_FOR_LOGGING", 64))
|
||||
BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS: Final = 256 * 1024
|
||||
REDACTED_BY_LITELLM: Final = "redacted-by-litellm"
|
||||
# in-memory stand-in handed to provider converters for redacted arguments; never stored
|
||||
REDACTED_TOOL_CALL_ARGUMENTS_PLACEHOLDER: Final = "{}"
|
||||
|
|
|
|||
|
|
@ -78,7 +78,10 @@ from litellm.litellm_core_utils.llm_cost_calc.tool_call_cost_tracking import (
|
|||
from litellm.litellm_core_utils.llm_cost_calc.usage_object_transformation import (
|
||||
InteractionsUsageObjectTransformation,
|
||||
)
|
||||
from litellm.litellm_core_utils.logging_utils import truncate_base64_in_messages
|
||||
from litellm.litellm_core_utils.logging_utils import (
|
||||
truncate_base64_in_messages,
|
||||
truncate_base64_in_messages_async,
|
||||
)
|
||||
from litellm.litellm_core_utils.model_param_helper import ModelParamHelper
|
||||
from litellm.litellm_core_utils.redact_messages import (
|
||||
redact_message_input_output_from_custom_logger,
|
||||
|
|
@ -538,6 +541,7 @@ class Logging(LiteLLMLoggingBaseClass):
|
|||
self.standard_built_in_tools_params: StandardBuiltInToolsParams = (
|
||||
self.initialize_standard_built_in_tools_params(kwargs)
|
||||
)
|
||||
self.truncated_messages_for_logging: str | list | dict | None = None # mutable-ok: logged messages shape
|
||||
## TIME TO FIRST TOKEN LOGGING ##
|
||||
self.completion_start_time: datetime.datetime | None = None
|
||||
self._llm_caching_handler: LLMCachingHandler | None = None
|
||||
|
|
@ -2933,6 +2937,11 @@ class Logging(LiteLLMLoggingBaseClass):
|
|||
result._hidden_params["batch_failed_requests"] = batch_result.failed_requests # pyright: ignore[reportPrivateUsage] # rebind-ok: same pattern as above
|
||||
result.usage = batch_result.usage
|
||||
|
||||
self.truncated_messages_for_logging = await truncate_base64_in_messages_async(
|
||||
StandardLoggingPayloadSetup.append_system_prompt_messages(
|
||||
kwargs=self.model_call_details, messages=self.model_call_details.get("messages")
|
||||
)
|
||||
)
|
||||
start_time, end_time, result = self._success_handler_helper_fn(
|
||||
start_time=start_time,
|
||||
end_time=end_time,
|
||||
|
|
@ -6202,9 +6211,13 @@ def get_standard_logging_object_payload(
|
|||
model_id=_model_id,
|
||||
requester_ip_address=clean_metadata.get("requester_ip_address", None),
|
||||
user_agent=clean_metadata.get("user_agent", None),
|
||||
messages=truncate_base64_in_messages(
|
||||
StandardLoggingPayloadSetup.append_system_prompt_messages(
|
||||
kwargs=kwargs, messages=kwargs.get("messages")
|
||||
messages=(
|
||||
logging_obj.truncated_messages_for_logging
|
||||
if logging_obj.truncated_messages_for_logging is not None
|
||||
else truncate_base64_in_messages(
|
||||
StandardLoggingPayloadSetup.append_system_prompt_messages(
|
||||
kwargs=kwargs, messages=kwargs.get("messages")
|
||||
)
|
||||
)
|
||||
),
|
||||
response=final_response_obj,
|
||||
|
|
|
|||
|
|
@ -3,12 +3,15 @@ import functools
|
|||
import inspect
|
||||
import re
|
||||
import time
|
||||
from collections.abc import Mapping
|
||||
from collections.abc import Iterator, Mapping, Sequence
|
||||
from datetime import datetime
|
||||
from typing import TYPE_CHECKING, Any, Final
|
||||
|
||||
from litellm._logging import verbose_logger
|
||||
from litellm.constants import MAX_BASE64_LENGTH_FOR_LOGGING
|
||||
from litellm.constants import (
|
||||
BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS,
|
||||
MAX_BASE64_LENGTH_FOR_LOGGING,
|
||||
)
|
||||
from litellm.types.utils import (
|
||||
ModelResponse,
|
||||
ModelResponseStream,
|
||||
|
|
@ -141,6 +144,39 @@ def truncate_base64_in_messages(
|
|||
return messages
|
||||
|
||||
|
||||
_StringTree = str | Sequence["_StringTree"] | Mapping[str, "_StringTree"] | None
|
||||
|
||||
|
||||
def _iter_string_leaves(value: _StringTree) -> Iterator[str]:
|
||||
stack: Final[list[_StringTree]] = [value] # mutable-ok: explicit stack, recursive functions are banned in litellm/
|
||||
while stack:
|
||||
match stack.pop():
|
||||
case str() as text:
|
||||
yield text
|
||||
case Mapping() as mapping:
|
||||
stack.extend(mapping.values())
|
||||
case Sequence() as items:
|
||||
stack.extend(items)
|
||||
case None:
|
||||
pass
|
||||
|
||||
|
||||
async def truncate_base64_in_messages_async(
|
||||
messages: str | list | dict | None, # mutable-ok: same contract as truncate_base64_in_messages
|
||||
) -> str | list | dict | None: # mutable-ok: same contract as truncate_base64_in_messages
|
||||
"""
|
||||
Same result as truncate_base64_in_messages, but payloads whose string content
|
||||
reaches BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS are scanned in a worker
|
||||
thread so the regex pass over multi-MB base64 images does not block the event loop.
|
||||
"""
|
||||
if messages is None or MAX_BASE64_LENGTH_FOR_LOGGING <= 0:
|
||||
return messages
|
||||
total_chars: Final = sum(len(leaf) for leaf in _iter_string_leaves(messages))
|
||||
if total_chars < BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS:
|
||||
return truncate_base64_in_messages(messages)
|
||||
return await asyncio.to_thread(truncate_base64_in_messages, messages)
|
||||
|
||||
|
||||
# Global service logger instance to avoid recreating it
|
||||
_service_logger = None
|
||||
|
||||
|
|
|
|||
|
|
@ -1114,6 +1114,56 @@ async def test_logging_non_streaming_request():
|
|||
litellm.callbacks = original_callbacks
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_async_success_handler_truncates_large_base64_off_the_event_loop(monkeypatch):
|
||||
"""The standard logging payload's base64 scan of a large multimodal request must not run on the loop thread."""
|
||||
import threading
|
||||
|
||||
from litellm.litellm_core_utils import logging_utils
|
||||
|
||||
loop_thread = threading.get_ident()
|
||||
scan_threads: list[int] = []
|
||||
original_scan = logging_utils._truncate_base64_in_string
|
||||
|
||||
def recording_scan(value: str) -> str:
|
||||
scan_threads.append(threading.get_ident())
|
||||
return original_scan(value)
|
||||
|
||||
monkeypatch.setattr(logging_utils, "_truncate_base64_in_string", recording_scan)
|
||||
monkeypatch.setattr(logging_utils, "BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS", 1_000)
|
||||
|
||||
logged = asyncio.Event()
|
||||
captured: dict = {}
|
||||
|
||||
class CaptureLogger(CustomLogger):
|
||||
async def async_log_success_event(self, kwargs, response_obj, start_time, end_time):
|
||||
captured["standard_logging_object"] = kwargs["standard_logging_object"]
|
||||
logged.set()
|
||||
|
||||
monkeypatch.setattr(litellm, "callbacks", [CaptureLogger()])
|
||||
payload = "L" * 20_000
|
||||
await litellm.acompletion(
|
||||
model="openai/gpt-5.6",
|
||||
messages=[
|
||||
{
|
||||
"role": "user",
|
||||
"content": [
|
||||
{"type": "text", "text": "describe"},
|
||||
{"type": "image_url", "image_url": {"url": f"data:image/png;base64,{payload}"}},
|
||||
],
|
||||
}
|
||||
],
|
||||
mock_response="ok",
|
||||
)
|
||||
await asyncio.wait_for(logged.wait(), timeout=10)
|
||||
|
||||
logged_url = captured["standard_logging_object"]["messages"][0]["content"][1]["image_url"]["url"]
|
||||
assert "base64_data truncated" in logged_url
|
||||
assert payload not in logged_url
|
||||
assert scan_threads
|
||||
assert loop_thread not in scan_threads
|
||||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"async_flag",
|
||||
[
|
||||
|
|
|
|||
|
|
@ -2,12 +2,16 @@
|
|||
Tests for litellm.litellm_core_utils.logging_utils — base64 truncation helpers.
|
||||
"""
|
||||
|
||||
import threading
|
||||
|
||||
import pytest
|
||||
|
||||
from litellm.litellm_core_utils import logging_utils
|
||||
from litellm.litellm_core_utils.logging_utils import (
|
||||
_format_base64_size,
|
||||
_truncate_base64_in_string,
|
||||
truncate_base64_in_messages,
|
||||
truncate_base64_in_messages_async,
|
||||
)
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
|
|
@ -157,3 +161,70 @@ class TestTruncateBase64InMessages:
|
|||
result[0]["content"][0]["image_url"]["url"]
|
||||
== f"data:image/png;base64,{short}"
|
||||
)
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# truncate_base64_in_messages_async
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _image_messages(payload: str) -> list:
|
||||
return [
|
||||
{
|
||||
"role": "user",
|
||||
"content": [
|
||||
{"type": "text", "text": "describe"},
|
||||
{"type": "image_url", "image_url": {"url": f"data:image/png;base64,{payload}"}},
|
||||
],
|
||||
}
|
||||
]
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def scan_threads(monkeypatch):
|
||||
"""Record the thread that runs every base64 regex scan."""
|
||||
threads: list[int] = []
|
||||
original = logging_utils._truncate_base64_in_string
|
||||
|
||||
def recording_scan(value: str) -> str:
|
||||
threads.append(threading.get_ident())
|
||||
return original(value)
|
||||
|
||||
monkeypatch.setattr(logging_utils, "_truncate_base64_in_string", recording_scan)
|
||||
return threads
|
||||
|
||||
|
||||
class TestTruncateBase64InMessagesAsync:
|
||||
@pytest.mark.asyncio
|
||||
async def test_large_payload_is_scanned_off_the_event_loop(self, monkeypatch, scan_threads):
|
||||
monkeypatch.setattr(logging_utils, "BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS", 1_000)
|
||||
payload = "I" * 20_000
|
||||
messages = _image_messages(payload)
|
||||
|
||||
result = await truncate_base64_in_messages_async(messages)
|
||||
offload_threads = tuple(scan_threads)
|
||||
|
||||
assert result == truncate_base64_in_messages(messages)
|
||||
assert payload not in result[0]["content"][1]["image_url"]["url"]
|
||||
assert payload in messages[0]["content"][1]["image_url"]["url"]
|
||||
assert offload_threads
|
||||
assert threading.get_ident() not in offload_threads
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_small_payload_stays_on_the_calling_thread(self, monkeypatch, scan_threads):
|
||||
monkeypatch.setattr(logging_utils, "BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS", 1_000)
|
||||
messages = _image_messages("J" * 200)
|
||||
|
||||
result = await truncate_base64_in_messages_async(messages)
|
||||
|
||||
assert result == truncate_base64_in_messages(messages)
|
||||
assert scan_threads
|
||||
assert set(scan_threads) == {threading.get_ident()}
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_none_and_disabled_truncation_short_circuit(self, monkeypatch, scan_threads):
|
||||
assert await truncate_base64_in_messages_async(None) is None
|
||||
monkeypatch.setattr(logging_utils, "MAX_BASE64_LENGTH_FOR_LOGGING", 0)
|
||||
messages = _image_messages("K" * 20_000)
|
||||
assert await truncate_base64_in_messages_async(messages) is messages
|
||||
assert scan_threads == []
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue