litellm/tests/test_litellm_rust/test_ocr_callbacks.py
2026-09-07 23:38:20 -07:00

314 lines
12 KiB
Python

import asyncio
import copy
import queue
import threading
from typing import Final
import pytest
import litellm
from litellm.integrations.custom_logger import CustomLogger
from tests.test_litellm_rust.callback_recorder import RecordingLogger
from tests.test_litellm_rust.contracts import (
OCR_DOCUMENT,
OCR_RESPONSE,
call_native_aocr,
call_native_ocr,
request_body,
request_headers,
)
from tests.test_litellm_rust.recording_server import RecordingServer, ResponseSpec
pytestmark = pytest.mark.requires_rust_extension
@pytest.fixture
def ocr_server(recording_server: RecordingServer) -> RecordingServer:
recording_server.default_response = ResponseSpec(body=OCR_RESPONSE)
return recording_server
def call_ocr(server: RecordingServer, callbacks: list[CustomLogger], **kwargs: object):
return call_native_ocr(server, callbacks=callbacks, **kwargs)
async def call_aocr(server: RecordingServer, callbacks: list[CustomLogger], **kwargs: object):
return await call_native_aocr(server, callbacks=callbacks, **kwargs)
def test_pre_call_receives_expected_provider_request(ocr_server: RecordingServer) -> None:
observations: Final = []
class Observe(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
observations.append((model, messages, copy.deepcopy(kwargs["additional_args"])))
call_ocr(ocr_server, [Observe()], pages=[0])
assert len(observations) == 1
model, messages, additional_args = observations[0]
assert model == "mistral-ocr-latest"
assert messages == [{"role": "user", "content": "default-message-value"}]
assert additional_args["api_base"] == f"{ocr_server.base_url}/v1/ocr"
assert additional_args["complete_input_dict"] == {
"model": "mistral-ocr-latest",
"document": OCR_DOCUMENT,
"pages": [0],
}
@pytest.mark.parametrize("raise_after_edit", [False, True])
def test_pre_call_body_edits_reach_later_callbacks_and_provider(
ocr_server: RecordingServer, raise_after_edit: bool
) -> None:
observed: Final = []
class Edit(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
request_body(kwargs)["include_image_base64"] = True
if raise_after_edit:
raise RuntimeError("audit exporter unavailable")
class Observe(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
observed.append(copy.deepcopy(request_body(kwargs)))
call_ocr(ocr_server, [Edit(), Observe()], include_image_base64=False)
assert observed[0]["include_image_base64"] is True
assert ocr_server.requests[0].body["include_image_base64"] is True
def test_pre_call_header_edits_reach_later_callbacks_and_provider(ocr_server: RecordingServer) -> None:
observed: Final = []
class Edit(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
request_headers(kwargs)["x-audit-tag"] = "reviewed"
class Observe(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
observed.append(dict(request_headers(kwargs)))
call_ocr(ocr_server, [Edit(), Observe()])
assert observed[0]["x-audit-tag"] == "reviewed"
assert ocr_server.requests[0].headers["x-audit-tag"] == "reviewed"
def test_pre_call_nested_mutation_updates_retained_references(ocr_server: RecordingServer) -> None:
original: Final = dict(OCR_DOCUMENT)
replacement_url: Final = "data:application/pdf;base64,ZGVm"
retained: Final = []
class Retain(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
retained.append(request_body(kwargs)["document"])
class Edit(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
request_body(kwargs)["document"]["document_url"] = replacement_url
call_native_ocr(
ocr_server,
document=original,
callbacks=[Retain(), Edit()],
)
assert retained[0]["document_url"] == replacement_url
assert original["document_url"] == replacement_url
assert ocr_server.requests[0].body["document"]["document_url"] == replacement_url
def test_pre_call_field_replacement_preserves_original_references(ocr_server: RecordingServer) -> None:
original: Final = dict(OCR_DOCUMENT)
replacement: Final = {"type": "document_url", "document_url": "data:application/pdf;base64,ZGVm"}
retained: Final = []
class RetainAndReplace(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
body = request_body(kwargs)
retained.append(body["document"])
body["document"] = replacement
call_native_ocr(
ocr_server,
document=original,
callbacks=[RetainAndReplace()],
)
assert retained[0] is original
assert original["document_url"] == OCR_DOCUMENT["document_url"]
assert ocr_server.requests[0].body["document"] == replacement
def test_pre_call_body_rebinding_does_not_replace_inflight_request(ocr_server: RecordingServer) -> None:
observed: Final = []
class Rebind(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
kwargs["additional_args"]["complete_input_dict"] = {"replacement": True}
class Observe(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
observed.append(request_body(kwargs))
call_ocr(ocr_server, [Rebind(), Observe()])
assert observed == [{"replacement": True}]
assert ocr_server.requests[0].body == {"model": "mistral-ocr-latest", "document": OCR_DOCUMENT}
def test_queued_payload_observes_later_callback_mutations(ocr_server: RecordingServer) -> None:
queued: Final = []
class QueuePayload(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
queued.append(request_body(kwargs))
class Edit(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
request_body(kwargs)["queued-edit"] = True
call_ocr(ocr_server, [QueuePayload(), Edit()])
assert queued[0]["queued-edit"] is True
def test_pre_call_state_reaches_terminal_callbacks(ocr_server: RecordingServer) -> None:
token: Final = object()
terminal_tokens: queue.SimpleQueue[object] = queue.SimpleQueue()
finished: Final = threading.Event()
class Stash(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
kwargs["test-token"] = token
def log_success_event(self, kwargs, response_obj, start_time, end_time):
terminal_tokens.put(kwargs["test-token"])
finished.set()
call_ocr(ocr_server, [Stash()])
assert finished.wait(10)
assert terminal_tokens.get_nowait() is token
@pytest.mark.asyncio
async def test_success_callbacks_receive_expected_context_and_response(ocr_server: RecordingServer) -> None:
recorder: Final = RecordingLogger()
await call_aocr(
ocr_server,
[recorder],
litellm_call_id="ocr-success",
metadata={"source": "callback-test"},
)
events: Final = await recorder.wait_for_async("async_log_success_event")
assert len(events) == 1
assert events[0].call_type == "aocr"
assert events[0].kwargs["litellm_call_id"] == "ocr-success"
assert events[0].kwargs["litellm_params"]["metadata"]["source"] == "callback-test"
assert events[0].response.pages[0].markdown == "native OCR response"
@pytest.mark.asyncio
async def test_failure_callbacks_receive_expected_context_and_error(ocr_server: RecordingServer) -> None:
ocr_server.enqueue(ResponseSpec(body={"message": "provider unavailable"}, status=500))
observations: Final = []
class Observe(CustomLogger):
def log_failure_event(self, kwargs, response_obj, start_time, end_time):
observations.append(("sync", kwargs["call_type"], kwargs["exception"], response_obj))
async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time):
observations.append(("async", kwargs["call_type"], kwargs["exception"], response_obj))
with pytest.raises(litellm.InternalServerError):
await call_aocr(ocr_server, [Observe()])
assert [observation[0] for observation in observations] == ["sync", "async"]
assert all(observation[1] == "aocr" for observation in observations)
assert all(isinstance(observation[2], litellm.InternalServerError) for observation in observations)
assert all(observation[3] is None for observation in observations)
@pytest.mark.asyncio
async def test_pre_call_runs_in_callers_execution_context(ocr_server: RecordingServer) -> None:
caller_loop: Final = asyncio.get_running_loop()
caller_thread: Final = threading.current_thread()
recorder: Final = RecordingLogger()
await call_aocr(ocr_server, [recorder])
events: Final = await recorder.wait_for_async("log_pre_api_call")
assert len(events) == 1
assert events[0].loop is caller_loop
assert events[0].thread is caller_thread
@pytest.mark.asyncio
async def test_ocr_failure_callbacks_receive_pre_call_state(ocr_server: RecordingServer) -> None:
ocr_server.enqueue(ResponseSpec(body={"message": "provider unavailable"}, status=500))
token: Final = object()
observed: Final = []
class TrackInFlightRequest(CustomLogger):
def log_pre_api_call(self, model, messages, kwargs):
kwargs["request-token"] = token
def log_failure_event(self, kwargs, response_obj, start_time, end_time):
observed.append(("sync", kwargs["request-token"]))
async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time):
observed.append(("async", kwargs["request-token"]))
with pytest.raises(litellm.InternalServerError):
await call_aocr(ocr_server, [TrackInFlightRequest()])
assert [event for event, _ in observed] == ["sync", "async"]
assert all(observed_token is token for _, observed_token in observed)
@pytest.mark.asyncio
async def test_ocr_failure_callback_error_does_not_mask_provider_error_or_later_callbacks(
ocr_server: RecordingServer,
) -> None:
ocr_server.enqueue(ResponseSpec(body={"message": "provider unavailable"}, status=500))
recorder: Final = RecordingLogger()
class UnavailableExporter(CustomLogger):
def log_failure_event(self, kwargs, response_obj, start_time, end_time):
raise RuntimeError("exporter unavailable")
async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time):
raise RuntimeError("exporter unavailable")
with pytest.raises(litellm.InternalServerError) as caught:
await call_aocr(ocr_server, [UnavailableExporter(), recorder])
sync_events: Final = tuple(event for event in recorder.events if event.name == "log_failure_event")
async_events: Final = tuple(event for event in recorder.events if event.name == "async_log_failure_event")
assert len(sync_events) == 1
assert len(async_events) == 1
assert sync_events[0].kwargs["exception"] is caught.value
assert async_events[0].kwargs["exception"] is caught.value
assert "async_log_success_event" not in recorder.names
def test_ocr_duplicate_callback_registration_dispatches_once(ocr_server: RecordingServer) -> None:
recorder: Final = RecordingLogger()
call_ocr(
ocr_server,
[recorder, recorder],
success_callback=[recorder],
failure_callback=[recorder],
)
recorder.wait_for("log_success_event")
assert recorder.names.count("log_pre_api_call") == 1
assert recorder.names.count("logging_hook") == 1
assert recorder.names.count("log_success_event") == 1
assert "log_failure_event" not in recorder.names