Merge pull request #39511 from BerriAI/litellm_spend_logs_provider_response_id

fix(spend_tracking): key /v1/messages spend rows on the msg_ id the client received
This commit is contained in:
Mateo Wang 2026-09-03 14:35:50 -07:00 committed by GitHub
commit 0c8510d47c
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
6 changed files with 309 additions and 50 deletions

View file

@ -414,6 +414,11 @@ def _resolve_vertex_location_for_cost(
return VertexBase.get_vertex_region(configured_location, model)
def _provider_response_id(source: object) -> str | None:
candidate: Final = source.get("id") if isinstance(source, dict) else getattr(source, "id", None)
return candidate if isinstance(candidate, str) and candidate else None
class Logging(LiteLLMLoggingBaseClass):
global \
supabaseClient, \
@ -3832,11 +3837,12 @@ class Logging(LiteLLMLoggingBaseClass):
if isinstance(result, ResponsesAPIResponse):
return self._translate_responses_api_response_to_model_response(result)
provider_response_id: Final = _provider_response_id(result)
httpx_response: Final = self.model_call_details.get("httpx_response", None)
if httpx_response and isinstance(httpx_response, httpx.Response):
result = litellm.AnthropicConfig().transform_response(
raw_response=httpx_response,
model_response=litellm.ModelResponse(),
model_response=litellm.ModelResponse(id=provider_response_id),
model=self.model,
messages=[],
logging_obj=self,
@ -3859,7 +3865,7 @@ class Logging(LiteLLMLoggingBaseClass):
status_code=200,
headers={},
),
model_response=litellm.ModelResponse(),
model_response=litellm.ModelResponse(id=provider_response_id),
json_mode=None,
speed=self.optional_params.get("speed") if self.optional_params else None,
)
@ -3882,7 +3888,7 @@ class Logging(LiteLLMLoggingBaseClass):
return LiteLLMResponsesTransformationHandler().transform_response(
model=self.model,
raw_response=result,
model_response=litellm.ModelResponse(),
model_response=litellm.ModelResponse(id=_provider_response_id(result)),
logging_obj=self,
request_data={},
messages=[],
@ -3897,7 +3903,7 @@ class Logging(LiteLLMLoggingBaseClass):
"usage-only ModelResponse to keep the spend_logs row.",
str(e),
)
model_response: Final = litellm.ModelResponse()
model_response: Final = litellm.ModelResponse(id=_provider_response_id(result))
model_response.model = self.model
usage: Final = getattr(result, "usage", None)
if usage is not None and ResponseAPILoggingUtils._is_response_api_usage(usage):

View file

@ -107,6 +107,7 @@ class AnthropicPassthroughLoggingHandler:
start_time=start_time,
end_time=end_time,
logging_obj=logging_obj,
response_id=optional_str(response_body.get("id")),
)
return {
@ -148,8 +149,9 @@ class AnthropicPassthroughLoggingHandler:
return model
@staticmethod
def _extract_model_from_anthropic_chunks(
def _extract_message_start_field(
all_chunks: Sequence[str | bytes],
field: str,
) -> str | None:
for raw in all_chunks:
text = raw.decode("utf-8") if isinstance(raw, bytes) else raw
@ -163,11 +165,23 @@ class AnthropicPassthroughLoggingHandler:
if not isinstance(data, dict):
continue
if data.get("type") == "message_start":
model = (data.get("message") or {}).get("model")
if model:
return model
value = (data.get("message") or {}).get(field)
if isinstance(value, str) and value:
return value
return None
@staticmethod
def _extract_model_from_anthropic_chunks(
all_chunks: Sequence[str | bytes],
) -> str | None:
return AnthropicPassthroughLoggingHandler._extract_message_start_field(all_chunks, "model")
@staticmethod
def _extract_response_id_from_anthropic_chunks(
all_chunks: Sequence[str | bytes],
) -> str | None:
return AnthropicPassthroughLoggingHandler._extract_message_start_field(all_chunks, "id")
@staticmethod
def _stream_was_interrupted(
all_chunks: Sequence[str | bytes],
@ -251,6 +265,7 @@ class AnthropicPassthroughLoggingHandler:
start_time: datetime,
end_time: datetime,
logging_obj: LiteLLMLoggingObj,
response_id: str | None = None,
):
"""
Create the standard logging object for Anthropic passthrough
@ -312,8 +327,7 @@ class AnthropicPassthroughLoggingHandler:
json.dumps(kwargs, indent=4, default=str),
)
# set litellm_call_id to logging response object
litellm_model_response.id = logging_obj.litellm_call_id
litellm_model_response.id = response_id or logging_obj.litellm_call_id
litellm_model_response.model = model
logging_obj.model_call_details["model"] = model
if not logging_obj.model_call_details.get("custom_llm_provider"):
@ -413,6 +427,7 @@ class AnthropicPassthroughLoggingHandler:
start_time=start_time,
end_time=end_time,
logging_obj=litellm_logging_obj,
response_id=AnthropicPassthroughLoggingHandler._extract_response_id_from_anthropic_chunks(all_chunks),
)
return {

View file

@ -168,6 +168,35 @@ def completed_responses_object(result: StreamingResponse) -> ResponsesObject | N
return completed[-1] if completed else None
class AnthropicMessageObject(BaseModel):
id: str
class AnthropicStreamEvent(BaseModel):
"""One SSE frame of a native Anthropic stream. Only `message_start` carries the
message, so it stays optional and the deltas validate as themselves."""
type: str
message: AnthropicMessageObject | None = None
def anthropic_message_id(result: StreamingResponse) -> str | None:
"""The `msg_...` id the caller was served, which is what the spend row is keyed by
on this route: off the `message_start` frame when streaming, off the body when not."""
if not result.is_streaming:
return AnthropicMessageObject.model_validate_json(result.body).id
events = (
AnthropicStreamEvent.model_validate_json(payload)
for payload in result.stream_events
)
started = tuple(
event.message
for event in events
if event.type == "message_start" and event.message is not None
)
return started[0].id if started else None
class OpenAIResponsesBody(BaseModel):
model: str
input: str

View file

@ -2,7 +2,8 @@
Each test sends a NATIVE provider request through the proxy's passthrough route
and verifies the proxy still logged a costed SpendLogs row
(call_type="pass_through_endpoint"), correlated by the x-litellm-call-id header.
(call_type="pass_through_endpoint"), correlated by the id the caller was served:
the x-litellm-call-id header on gemini, the `msg_...` message id on anthropic.
Covered: gemini ("gemini-2.5-flash") + anthropic ("claude-haiku-4-5"), streaming +
non-streaming, plus native tool calls. See LLM_TRANSLATION_COVERAGE_MATRIX.md.
@ -14,7 +15,7 @@ A passthrough call returning non-2xx fails hard (never a skip); once it returns
import pytest
from e2e_config import CHEAP_OPENAI_MODEL, unique_marker
from e2e_http import StreamingResponse, require_successful_call, unwrap
from e2e_http import require_successful_call, unwrap
from lifecycle import ResourceManager
from models import KeyGenerateBody, SpendLogRow
from passthrough_client import (
@ -24,6 +25,7 @@ from passthrough_client import (
JsonSchema,
JsonSchemaProperty,
PassthroughClient,
anthropic_message_id,
completed_responses_object,
)
@ -33,18 +35,18 @@ REALTIME_MODEL = "gpt-realtime-2"
pytestmark = pytest.mark.e2e
def _fetch_cost_breakdown(client: PassthroughClient, result: StreamingResponse) -> SpendLogRow:
def _fetch_cost_breakdown(client: PassthroughClient, request_id: str | None) -> SpendLogRow:
"""The passthrough call's logged row, polled until it carries a cost.
Asserts (not skips) that a 2xx passthrough call produced a costed row - the
whole point of passthrough spend tracking.
"""
assert result.call_id, "passthrough response had no x-litellm-call-id header"
assert request_id, "passthrough response carried no id to correlate its spend row by"
rows = client.proxy.poll_logs_for_request_id(
result.call_id,
request_id,
predicate=lambda rs: (rs[0].spend or 0) > 0,
)
assert rows, f"no SpendLogs row for passthrough call_id {result.call_id}"
assert rows, f"no SpendLogs row for passthrough request_id {request_id}"
row = rows[0]
assert row.call_type == "pass_through_endpoint"
assert (row.spend or 0) > 0, f"passthrough call was not costed: {row}"
@ -64,7 +66,7 @@ def test_gemini_passthrough_nonstreaming_logs_cost(
)
require_successful_call(result)
row = _fetch_cost_breakdown(client, result)
row = _fetch_cost_breakdown(client, result.call_id)
assert row.custom_llm_provider == "gemini"
assert "gemini" in (row.model or "")
assert tag in (row.request_tags or []), f"tags not logged: {row.request_tags}"
@ -107,7 +109,7 @@ def test_gemini_passthrough_streaming_logs_cost(
require_successful_call(result)
assert result.chunks > 0, "streaming passthrough produced no events"
row = _fetch_cost_breakdown(client, result)
row = _fetch_cost_breakdown(client, result.call_id)
assert row.custom_llm_provider == "gemini"
@ -137,7 +139,7 @@ def test_gemini_passthrough_tool_call_logs_cost(
require_successful_call(result)
assert "functionCall" in result.body, "gemini did not emit a tool call"
row = _fetch_cost_breakdown(client, result)
row = _fetch_cost_breakdown(client, result.call_id)
assert row.custom_llm_provider == "gemini"
@ -150,7 +152,7 @@ def test_anthropic_passthrough_nonstreaming_logs_cost(
result = client.anthropic_message(scoped_key, "claude-haiku-4-5", "Say hello")
require_successful_call(result)
row = _fetch_cost_breakdown(client, result)
row = _fetch_cost_breakdown(client, anthropic_message_id(result))
assert row.custom_llm_provider == "anthropic"
assert "claude" in (row.model or "")
@ -164,7 +166,7 @@ def test_anthropic_passthrough_streaming_logs_cost(
require_successful_call(result)
assert result.chunks > 0, "streaming passthrough produced no events"
row = _fetch_cost_breakdown(client, result)
row = _fetch_cost_breakdown(client, anthropic_message_id(result))
assert row.custom_llm_provider == "anthropic"
@ -190,7 +192,7 @@ def test_anthropic_passthrough_tool_call_logs_cost(
require_successful_call(result)
assert "tool_use" in result.body, "anthropic did not emit a tool call"
row = _fetch_cost_breakdown(client, result)
row = _fetch_cost_breakdown(client, anthropic_message_id(result))
assert row.custom_llm_provider == "anthropic"

View file

@ -50,9 +50,9 @@ async def test_anthropic_basic_completion_with_headers():
anthropic_api_output_tokens = (
reported_usage.get("output_tokens", None) if reported_usage else None
)
litellm_call_id = response_headers.get("x-litellm-call-id")
anthropic_message_id = response_json.get("id")
print(f"LiteLLM Call ID: {litellm_call_id}")
print(f"Anthropic message ID: {anthropic_message_id}")
# Wait for spend to be logged
await asyncio.sleep(15)
@ -64,7 +64,7 @@ async def test_anthropic_basic_completion_with_headers():
print(f"Attempt {attempt + 1}/{max_retries} to check spend logs")
async with session.get(
f"http://0.0.0.0:4000/spend/logs?request_id={litellm_call_id}",
f"http://0.0.0.0:4000/spend/logs?request_id={anthropic_message_id}",
headers={"Authorization": "Bearer sk-1234"},
) as spend_response:
print("text spend response")
@ -84,25 +84,25 @@ async def test_anthropic_basic_completion_with_headers():
print("Waiting 10 seconds before retry...")
await asyncio.sleep(10)
# Spend data might be unavailable (auth error, slow DB write, etc.)
if (
spend_data is None
or not isinstance(spend_data, list)
or len(spend_data) == 0
or not isinstance(spend_data[0], dict)
or "request_id" not in spend_data[0]
):
print(f"Spend data not available or is error response: {spend_data}")
print("Skipping spend assertions (DB write may be slow in CI)")
if not isinstance(spend_data, list):
print(f"Spend endpoint answered with an error response: {spend_data}")
print("Skipping spend assertions (spend logs unreachable in CI)")
return
assert spend_data, (
f"GET /spend/logs?request_id={anthropic_message_id} found no row for the id "
"the caller received"
)
log_entry = spend_data[0]
# Basic existence checks
assert isinstance(log_entry, dict), "Log entry should be a dictionary"
# Request metadata assertions
assert log_entry["request_id"] == litellm_call_id, "Request ID should match"
assert (
log_entry["request_id"] == anthropic_message_id
), "Request ID should be the message id the caller received"
assert (
log_entry["call_type"] == "pass_through_endpoint"
), "Call type should be pass_through_endpoint"
@ -182,8 +182,6 @@ async def test_anthropic_streaming_with_headers():
assert response.status == 200, "Response should be successful"
response_headers = response.headers
print(f"Response headers: {response_headers}")
litellm_call_id = response_headers.get("x-litellm-call-id")
print(f"LiteLLM Call ID: {litellm_call_id}")
collected_output = []
async for line in response.content:
@ -194,13 +192,18 @@ async def test_anthropic_streaming_with_headers():
print("Collected output:", "".join(collected_output))
anthropic_api_usage_chunks = []
anthropic_message_id = None
for chunk in collected_output:
chunk_json = json.loads(chunk)
if chunk_json.get("type") == "message_start":
anthropic_message_id = chunk_json.get("message", {}).get("id")
if "usage" in chunk_json:
anthropic_api_usage_chunks.append(chunk_json["usage"])
elif "message" in chunk_json and "usage" in chunk_json["message"]:
anthropic_api_usage_chunks.append(chunk_json["message"]["usage"])
print(f"Anthropic message ID: {anthropic_message_id}")
print(
"anthropic_api_usage_chunks",
json.dumps(anthropic_api_usage_chunks, indent=4, default=str),
@ -232,7 +235,7 @@ async def test_anthropic_streaming_with_headers():
print(f"Attempt {attempt + 1}/{max_retries} to check spend logs")
async with session.get(
f"http://0.0.0.0:4000/spend/logs?request_id={litellm_call_id}",
f"http://0.0.0.0:4000/spend/logs?request_id={anthropic_message_id}",
headers={"Authorization": "Bearer sk-1234"},
) as spend_response:
spend_data = await spend_response.json()
@ -250,25 +253,25 @@ async def test_anthropic_streaming_with_headers():
print("Waiting 10 seconds before retry...")
await asyncio.sleep(10)
# Spend data might be unavailable (auth error, slow DB write, etc.)
if (
spend_data is None
or not isinstance(spend_data, list)
or len(spend_data) == 0
or not isinstance(spend_data[0], dict)
or "request_id" not in spend_data[0]
):
print(f"Spend data not available or is error response: {spend_data}")
print("Skipping spend assertions (DB write may be slow in CI)")
if not isinstance(spend_data, list):
print(f"Spend endpoint answered with an error response: {spend_data}")
print("Skipping spend assertions (spend logs unreachable in CI)")
return
assert spend_data, (
f"GET /spend/logs?request_id={anthropic_message_id} found no row for the id "
"the caller received"
)
log_entry = spend_data[0]
# Basic existence checks
assert isinstance(log_entry, dict), "Log entry should be a dictionary"
# Request metadata assertions
assert log_entry["request_id"] == litellm_call_id, "Request ID should match"
assert (
log_entry["request_id"] == anthropic_message_id
), "Request ID should be the message id the caller received"
assert (
log_entry["call_type"] == "pass_through_endpoint"
), "Call type should be pass_through_endpoint"

View file

@ -3956,3 +3956,207 @@ def test_caller_forged_router_metadata_is_discarded(bucket):
)
metadata = json.loads(payload["metadata"])
assert metadata["router_metadata"] is None
ANTHROPIC_MESSAGES_RESPONSE: Final = {
"id": "msg_01Lit6806NonStreaming",
"type": "message",
"role": "assistant",
"model": "claude-haiku-4-5",
"content": [{"type": "text", "text": "epsilon"}],
"stop_reason": "end_turn",
"stop_sequence": None,
"usage": {"input_tokens": 14, "output_tokens": 4},
}
ANTHROPIC_MESSAGES_SSE_CHUNKS: Final = (
'event: message_start\ndata: {"type":"message_start","message":{"id":"msg_01Lit6806Streaming",'
'"type":"message","role":"assistant","model":"claude-haiku-4-5","content":[],'
'"usage":{"input_tokens":14,"output_tokens":1}}}\n\n',
'event: content_block_start\ndata: {"type":"content_block_start","index":0,'
'"content_block":{"type":"text","text":""}}\n\n',
'event: content_block_delta\ndata: {"type":"content_block_delta","index":0,'
'"delta":{"type":"text_delta","text":"epsilon"}}\n\n',
'event: content_block_stop\ndata: {"type":"content_block_stop","index":0}\n\n',
'event: message_delta\ndata: {"type":"message_delta","delta":{"stop_reason":"end_turn"},'
'"usage":{"output_tokens":4}}\n\n',
"event: message_stop\ndata: {\"type\":\"message_stop\"}\n\n",
)
def _anthropic_messages_logging_obj(*, stream: bool) -> Any:
from litellm.litellm_core_utils.litellm_logging import Logging
logging_obj = Logging(
model="claude-haiku-4-5",
messages=[{"role": "user", "content": "hi"}],
stream=stream,
call_type="anthropic_messages",
start_time=datetime.datetime.now(timezone.utc),
litellm_call_id="6806cafe-0000-4000-8000-000000000001",
function_id="1234",
)
logging_obj.optional_params = {}
logging_obj.model_call_details["custom_llm_provider"] = "anthropic"
return logging_obj
def _spend_log_request_id(response_obj: Any, kwargs: dict) -> str:
payload = get_logging_payload(
kwargs=kwargs,
response_obj=response_obj,
start_time=datetime.datetime.now(timezone.utc),
end_time=datetime.datetime.now(timezone.utc),
)
return payload["request_id"]
def test_spend_log_request_id_is_the_message_id_a_non_streaming_messages_caller_received():
"""
POST /v1/messages hands the caller `id: msg_...`, the only request id they ever see, so
GET /spend/logs?request_id=msg_... has to find the row.
"""
logging_obj = _anthropic_messages_logging_obj(stream=False)
logged_response = logging_obj._handle_anthropic_messages_response_logging(
result=ANTHROPIC_MESSAGES_RESPONSE
)
assert logged_response.id == "msg_01Lit6806NonStreaming"
assert (
_spend_log_request_id(
response_obj=logged_response,
kwargs={
"call_type": "anthropic_messages",
"model": "claude-haiku-4-5",
"litellm_call_id": "6806cafe-0000-4000-8000-000000000001",
"litellm_params": {"metadata": {"user_api_key": "test-key"}},
},
)
== "msg_01Lit6806NonStreaming"
)
def test_spend_log_request_id_is_the_message_id_a_streaming_messages_caller_received():
"""
The streaming leg of /v1/messages logs through the Anthropic passthrough handler, which used
to stamp litellm_call_id over the msg_ id carried by the message_start event.
"""
from litellm.proxy.pass_through_endpoints.llm_provider_handlers.anthropic_passthrough_logging_handler import (
AnthropicPassthroughLoggingHandler,
)
from litellm.types.passthrough_endpoints.pass_through_endpoints import EndpointType
logging_obj = _anthropic_messages_logging_obj(stream=True)
logging_obj.model_call_details["stream"] = True
logged = AnthropicPassthroughLoggingHandler._handle_logging_anthropic_collected_chunks(
litellm_logging_obj=logging_obj,
passthrough_success_handler_obj=MagicMock(),
url_route="/v1/messages",
request_body={"model": "claude-haiku-4-5"},
endpoint_type=EndpointType.ANTHROPIC,
start_time=datetime.datetime.now(timezone.utc),
all_chunks=list(ANTHROPIC_MESSAGES_SSE_CHUNKS),
end_time=datetime.datetime.now(timezone.utc),
)
assert logged["result"].id == "msg_01Lit6806Streaming"
assert (
_spend_log_request_id(
response_obj=logged["result"],
kwargs={
**logged["kwargs"],
"call_type": "anthropic_messages",
"litellm_call_id": "6806cafe-0000-4000-8000-000000000001",
"litellm_params": {"metadata": {"user_api_key": "test-key"}},
},
)
== "msg_01Lit6806Streaming"
)
def test_spend_log_request_id_still_falls_back_to_litellm_call_id_without_a_provider_id():
"""
Anthropic-compatible upstreams that omit `id` must keep landing on litellm_call_id rather
than on a fresh chatcmpl- uuid nobody can look up.
"""
logging_obj = _anthropic_messages_logging_obj(stream=True)
logging_obj.model_call_details["stream"] = True
from litellm.proxy.pass_through_endpoints.llm_provider_handlers.anthropic_passthrough_logging_handler import (
AnthropicPassthroughLoggingHandler,
)
AnthropicPassthroughLoggingHandler._create_anthropic_response_logging_payload(
litellm_model_response=litellm.ModelResponse(id="chatcmpl-generated"),
model="claude-haiku-4-5",
kwargs={},
start_time=datetime.datetime.now(timezone.utc),
end_time=datetime.datetime.now(timezone.utc),
logging_obj=logging_obj,
)
assert logging_obj.model_call_details["complete_streaming_response"].id == (
"6806cafe-0000-4000-8000-000000000001"
)
def test_spend_log_request_id_for_chat_completions_is_untouched():
"""
/v1/chat/completions callers look their rows up by the chatcmpl- id in the response body.
"""
assert (
_spend_log_request_id(
response_obj=litellm.ModelResponse(id="chatcmpl-EJvWIw3DAhuKYuwp3jJI4Pnhp2vjv", choices=[]),
kwargs={
"call_type": "acompletion",
"model": "gpt-5.6",
"litellm_call_id": "6806cafe-0000-4000-8000-000000000002",
"litellm_params": {"metadata": {"user_api_key": "test-key"}},
},
)
== "chatcmpl-EJvWIw3DAhuKYuwp3jJI4Pnhp2vjv"
)
def test_spend_log_request_id_is_the_response_id_a_bridged_messages_caller_received():
"""
/v1/messages against a non-Anthropic model answers with the Responses id the caller then
looks their row up by, so the row must not fall back to a fresh chatcmpl- uuid.
"""
from litellm.types.llms.openai import ResponseAPIUsage, ResponsesAPIResponse
logging_obj = _anthropic_messages_logging_obj(stream=False)
bridged_response = ResponsesAPIResponse(
id="resp_01Lit6806Bridged",
object="response",
created_at=1767225600,
model="gpt-5.6",
status="completed",
output=[
{
"id": "msg_bridged_output",
"type": "message",
"role": "assistant",
"status": "completed",
"content": [{"type": "output_text", "text": "delta", "annotations": []}],
}
],
usage=ResponseAPIUsage(input_tokens=13, output_tokens=5, total_tokens=18),
)
logged_response = logging_obj._handle_anthropic_messages_response_logging(result=bridged_response)
assert logged_response.id == "resp_01Lit6806Bridged"
assert (
_spend_log_request_id(
response_obj=logged_response,
kwargs={
"call_type": "anthropic_messages",
"model": "gpt-5.6",
"litellm_call_id": "6806cafe-0000-4000-8000-000000000003",
"litellm_params": {"metadata": {"user_api_key": "test-key"}},
},
)
== "resp_01Lit6806Bridged"
)