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
This commit is contained in:
mubashir1osmani 2026-08-13 14:02:22 -07:00
parent 2f7b0db25e
commit 499f593a03
2 changed files with 88 additions and 29 deletions

View file

@ -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,

View file

@ -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"]