From 499f593a030bb71d05628f464056bbbc79686d65 Mon Sep 17 00:00:00 2001 From: mubashir1osmani Date: Thu, 13 Aug 2026 14:02:22 -0700 Subject: [PATCH] fix(otel): skip tenant routing on deferred pre_call route_for ran before the recordable-parent check, so a thread-pool pre_call still built or LRU-touched a tenant provider and could evict an idle one even though the hold was released immediately and close re-routed. Only route when the span actually opens --- litellm/integrations/otel/logger.py | 66 +++++++++++-------- .../integrations/otel/test_otel_v2_logger.py | 51 ++++++++++++++ 2 files changed, 88 insertions(+), 29 deletions(-) diff --git a/litellm/integrations/otel/logger.py b/litellm/integrations/otel/logger.py index d5014ec46ca..e4dfa31e594 100644 --- a/litellm/integrations/otel/logger.py +++ b/litellm/integrations/otel/logger.py @@ -279,43 +279,37 @@ class OpenTelemetryV2(CustomLogger): if call_id in self._open_llm_calls: return start_time_ns: Final = to_ns(datetime.now()) - span: Span | None = None # Parent to the request's anchored root span (stable across the request), # falling back to ambient on the SDK path. Open the span live only when # that resolves to a recordable parent; otherwise defer to the close # callback (the thread-pool case, where the anchor isn't visible here). + # Do not route on the deferred path: creating or LRU-touching a tenant + # provider here would evict idle ones even though close re-routes. + parent_context: Final = resolve_request_span_context() + if not is_recordable_span(get_current_span(parent_context)): + self._store_open_call(call_id, _LLMCallSpan(span=None, start_time_ns=start_time_ns)) + return # A detached route roots its own trace instead (linked to the request # trace) — see ``TenantRoute.detached``. route: Final = self._tenant_tracers.route_for(self.tracer, call.dynamic_params, call.auth_metadata) - parent_context: Final = resolve_request_span_context() try: - if is_recordable_span(get_current_span(parent_context)): - span = self._emitter.start_span( - SpanRole.LLM_CALL, - call.provisional_span_name, - parent_context=( - set_span_in_context(INVALID_SPAN, parent_context) if route.detached else parent_context - ), - start_time_ns=start_time_ns, - tracer=route.tracer, - links=_request_trace_links(parent_context) if route.detached else None, - ) - finally: - # No span means route_for's hold has no owner (creation deferred to - # the close callback, which re-routes) — drop it here. - if span is None: - self._tenant_tracers.release(route.provider) - self._open_llm_calls[call_id] = _LLMCallSpan( - span=span, - start_time_ns=start_time_ns, - provider=route.provider if span is not None else None, + span: Final = self._emitter.start_span( + SpanRole.LLM_CALL, + call.provisional_span_name, + parent_context=( + set_span_in_context(INVALID_SPAN, parent_context) if route.detached else parent_context + ), + start_time_ns=start_time_ns, + tracer=route.tracer, + links=_request_trace_links(parent_context) if route.detached else None, + ) + except BaseException: + self._tenant_tracers.release(route.provider) + raise + self._store_open_call( + call_id, + _LLMCallSpan(span=span, start_time_ns=start_time_ns, provider=route.provider), ) - # Evict the oldest open call if the map is over budget. A call that opens - # but never closes (a stream that only fires stream events) would linger - # otherwise; the evicted span is simply dropped (never exported). - if len(self._open_llm_calls) > _OPEN_CALLS_MAX: - _, evicted = self._open_llm_calls.popitem(last=False) - self._release_carrier(evicted) async def async_log_success_event(self, kwargs, response_obj, start_time, end_time): if self._emit_mcp_tool_call(kwargs, start_time, end_time): @@ -494,6 +488,18 @@ class OpenTelemetryV2(CustomLogger): # force-flushes it out rather than racing its enqueue. self._release_carrier(carrier) + def _store_open_call(self, call_id: str, carrier: _LLMCallSpan) -> None: + """Remember an in-flight LLM call, evicting the oldest if over budget. + + A call that opens but never closes (a stream that only fires stream + events) would linger otherwise; the evicted span is simply dropped + (never exported). + """ + self._open_llm_calls[call_id] = carrier + if len(self._open_llm_calls) > _OPEN_CALLS_MAX: + _, evicted = self._open_llm_calls.popitem(last=False) + self._release_carrier(evicted) + def _release_carrier(self, carrier: "_LLMCallSpan | None") -> None: """Release the routed provider a removed carrier was holding open.""" if carrier is not None: @@ -531,7 +537,9 @@ class OpenTelemetryV2(CustomLogger): # consistently. A detached route roots its own trace instead, linked back. route: Final = self._tenant_tracers.route_for(self.tracer, call.dynamic_params, call.auth_metadata) try: - parent_ctx = self._seed_identity_baggage(data.identity, data.request_model, resolve_request_span_context()) + parent_ctx: Final = self._seed_identity_baggage( + data.identity, data.request_model, resolve_request_span_context() + ) return self._emitter.emit( SpanRole.LLM_CALL, data, diff --git a/tests/test_litellm/integrations/otel/test_otel_v2_logger.py b/tests/test_litellm/integrations/otel/test_otel_v2_logger.py index 4a03fbda7e4..7373d6f9e08 100644 --- a/tests/test_litellm/integrations/otel/test_otel_v2_logger.py +++ b/tests/test_litellm/integrations/otel/test_otel_v2_logger.py @@ -2439,3 +2439,54 @@ def test_evicted_provider_still_exports_span_opened_before_eviction(monkeypatch) headers_a = next(h for h in captured if "proj-a" in h) assert [s.name for s in captured[headers_a].get_finished_spans()] == ["chat gpt-4o"] + + +def test_deferred_pre_call_does_not_churn_tenant_cache(monkeypatch): + """Deferred ``pre_call`` must not create or LRU-touch a tenant provider. + + ``route_for`` used to run before the recordable-parent check, so a + thread-pool ``pre_call`` that immediately released its hold still built a + provider and could evict an idle one. Close re-routes when the span + actually opens. + """ + from litellm.integrations.otel.plumbing import routing as routing_mod + + monkeypatch.setattr(routing_mod, "_MAX_CACHED_PROVIDERS", 1) + shut_down = [] + monkeypatch.setattr(routing_mod, "_shutdown_provider", lambda p: shut_down.append(p)) + logger, _default, captured = _phoenix_routing_logger("capture_deferred_churn") + md_a = {"user_api_key_auth_metadata": {"phoenix_project_name": "proj-a"}} + server = logger._emitter.start_span( + SpanRole.PROXY_REQUEST, LITELLM_PROXY_REQUEST_SPAN_NAME + ) + with trace.use_span(server, end_on_exit=False): + _emit_llm( + logger, + { + "standard_logging_object": _payload(litellm_call_id="call_a", metadata=md_a), + "litellm_params": {"metadata": md_a}, + }, + ambient=server, + ) + assert len(logger._tenant_tracers._providers) == 1 + idle = next(iter(logger._tenant_tracers._providers.values())) + assert shut_down == [] + + md_b = {"user_api_key_auth_metadata": {"phoenix_project_name": "proj-b"}} + deferred_kwargs = { + "litellm_call_id": "call_b", + "standard_logging_object": _payload(litellm_call_id="call_b", metadata=md_b), + "litellm_params": {"metadata": md_b}, + } + logger.log_pre_api_call(model="gpt-4o", messages=[], kwargs=deferred_kwargs) + carrier = logger._open_llm_calls["call_b"] + assert carrier.span is None + assert carrier.provider is None + assert list(logger._tenant_tracers._providers.values()) == [idle] + assert shut_down == [] + assert captured and all("proj-b" not in headers for headers in captured) + + asyncio.run(logger.async_log_success_event(deferred_kwargs, None, None, None)) + server.end() + headers_b = next(h for h in captured if "proj-b" in h) + assert [s.name for s in captured[headers_b].get_finished_spans()] == ["chat gpt-4o"]