diff --git a/litellm/integrations/opentelemetry.py b/litellm/integrations/opentelemetry.py index 62aa2c24e74..cad9792c969 100644 --- a/litellm/integrations/opentelemetry.py +++ b/litellm/integrations/opentelemetry.py @@ -240,7 +240,9 @@ def _freeze_for_dedupe(value: object, _depth: int = 0) -> HashableScope: return repr(value) -def _is_unbilled_non_inference(call_type: object, litellm_params: Mapping[str, Any]) -> bool: +def _is_unbilled_non_inference( + call_type: str | None, litellm_params: Mapping[str, object] | None, response_obj: object +) -> bool: """Whether this call is a read or management route whose token counts describe an earlier request rather than this one. @@ -251,7 +253,10 @@ def _is_unbilled_non_inference(call_type: object, litellm_params: Mapping[str, A return False from litellm.litellm_core_utils.litellm_logging import StandardLoggingPayloadSetup - return is_unbilled_non_inference_call(call_type, StandardLoggingPayloadSetup.merge_litellm_metadata(litellm_params)) + metadata: Final = ( + StandardLoggingPayloadSetup.merge_litellm_metadata(litellm_params) if litellm_params is not None else None + ) + return is_unbilled_non_inference_call(call_type, metadata, response_obj) def _shutdown_tracer_provider(provider: "_SDKTracerProvider") -> None: @@ -1660,10 +1665,10 @@ class OpenTelemetry(OTELGenAISemconvMixin, CustomLogger): if self._operation_duration_histogram: self._operation_duration_histogram.record(duration_s, attributes=common_attrs) if ( - response_obj - and not _is_unbilled_non_inference(kwargs.get("call_type"), params) + self._token_usage_histogram + and response_obj + and not _is_unbilled_non_inference(kwargs.get("call_type"), params, response_obj) and (usage := response_obj.get("usage")) - and self._token_usage_histogram ): in_attrs: Final = {**common_attrs, TOKEN_TYPE_ATTRIBUTE: "input"} out_attrs: Final = {**common_attrs, TOKEN_TYPE_ATTRIBUTE: "output"} @@ -1740,6 +1745,9 @@ class OpenTelemetry(OTELGenAISemconvMixin, CustomLogger): if not self._time_per_output_token_histogram: return + if _is_unbilled_non_inference(kwargs.get("call_type"), kwargs.get("litellm_params"), response_obj): + return + # Get completion tokens from response_obj completion_tokens = None if response_obj and (usage := response_obj.get("usage")): @@ -2491,7 +2499,8 @@ class OpenTelemetry(OTELGenAISemconvMixin, CustomLogger): usage: Final = ( response_obj.get("usage") - if response_obj and not _is_unbilled_non_inference(kwargs.get("call_type"), litellm_params) + if response_obj + and not _is_unbilled_non_inference(kwargs.get("call_type"), litellm_params, response_obj) else None ) if usage: diff --git a/litellm/litellm_core_utils/internal_call_metadata.py b/litellm/litellm_core_utils/internal_call_metadata.py index 58ee5b4e18f..05c857f8c89 100644 --- a/litellm/litellm_core_utils/internal_call_metadata.py +++ b/litellm/litellm_core_utils/internal_call_metadata.py @@ -45,12 +45,35 @@ budget-checked like the request that spawned it. Everything else on the parent's be a lie on a sub-call that runs after it returned.""" -def is_unbilled_non_inference_call(call_type: str | None, metadata: Mapping[str, object] | None) -> bool: - """A read/management route priced at zero, except when the background response cost - poller made the read: that poll is the only place a background job's usage is ever - seen, so its retrieval carries the job's real spend.""" +def is_background_response(response: object) -> bool: + """Whether a retrieved object is a response created with ``background=true``. + + Such a create returns ``status="queued"`` and no usage at all, so nothing has billed the + job by the time anyone reads it back. Accepts the response as a mapping or a model, + because the callers hold it in both shapes. + """ + if isinstance(response, Mapping): + return response.get("background") is True + return getattr(response, "background", None) is True + + +def is_unbilled_non_inference_call( + call_type: str | None, + metadata: Mapping[str, object] | None, + response: object, +) -> bool: + """A read/management route priced at zero, because the usage it reports belongs to the + call that created the object it just read. + + Retrieving a background response is the exception, and the enterprise cost poller's read + is the same exception seen from the other side: that job's create billed nothing, so its + retrieval is the only place the spend is ever visible. Pricing those at zero would lose + the spend rather than deduplicate it. + """ if call_type not in NON_INFERENCE_CALL_TYPES: return False + if is_background_response(response): + return False if metadata is None: return True return metadata.get(INTERNAL_CALL_ORIGIN_METADATA_KEY) != BACKGROUND_RESPONSE_COST_POLL_CALL_ORIGIN diff --git a/litellm/litellm_core_utils/litellm_logging.py b/litellm/litellm_core_utils/litellm_logging.py index 26a12a4681a..47eb3854ac1 100644 --- a/litellm/litellm_core_utils/litellm_logging.py +++ b/litellm/litellm_core_utils/litellm_logging.py @@ -1581,7 +1581,7 @@ class Logging(LiteLLMLoggingBaseClass): return 0.0 if is_unbilled_non_inference_call( - self.call_type, StandardLoggingPayloadSetup.merge_litellm_metadata(self.litellm_params) + self.call_type, StandardLoggingPayloadSetup.merge_litellm_metadata(self.litellm_params), result ): return 0.0 @@ -4923,7 +4923,7 @@ class StandardLoggingPayloadSetup: return messages @staticmethod - def merge_litellm_metadata(litellm_params: dict) -> dict: + def merge_litellm_metadata(litellm_params: Mapping[str, object]) -> dict: """ Merge both litellm_metadata and metadata from litellm_params. @@ -5680,7 +5680,7 @@ def get_standard_logging_object_payload( cache_hit: Final = kwargs.get("cache_hit", False) # Extract usage as a plain dict, avoiding Pydantic round-trip raw_usage_dict: Final = StandardLoggingPayloadSetup.get_usage_as_dict( - response_obj=None if is_unbilled_non_inference_call(call_type, metadata) else response_obj, + response_obj=None if is_unbilled_non_inference_call(call_type, metadata, response_obj) else response_obj, combined_usage_object=cast(Usage | None, kwargs.get("combined_usage_object")), ) usage_dict: Final = ( diff --git a/litellm/proxy/spend_tracking/spend_tracking_utils.py b/litellm/proxy/spend_tracking/spend_tracking_utils.py index 3f2ca0ae96a..40e9dc0c3b4 100644 --- a/litellm/proxy/spend_tracking/spend_tracking_utils.py +++ b/litellm/proxy/spend_tracking/spend_tracking_utils.py @@ -276,7 +276,7 @@ def get_logging_payload(kwargs, response_obj, start_time, end_time) -> SpendLogs usage: dict = {} if call_type in ["ocr", "aocr"]: usage = _extract_usage_for_ocr_call(response_obj, response_obj_dict) - elif not is_unbilled_non_inference_call(call_type, metadata): + elif not is_unbilled_non_inference_call(call_type, metadata, response_obj_dict): # Use response_obj_dict instead of response_obj to avoid calling .get() on Pydantic models _usage: Final = response_obj_dict.get("usage", None) or {} if isinstance(_usage, litellm.Usage): diff --git a/tests/test_litellm/integrations/test_opentelemetry.py b/tests/test_litellm/integrations/test_opentelemetry.py index e0cdd7519ff..9ec8489f784 100644 --- a/tests/test_litellm/integrations/test_opentelemetry.py +++ b/tests/test_litellm/integrations/test_opentelemetry.py @@ -6356,6 +6356,7 @@ class TestOpenTelemetryNonInferenceUsage(unittest.TestCase): TOKEN_KEYS = frozenset({"gen_ai.usage.input_tokens", "gen_ai.usage.output_tokens", "gen_ai.usage.total_tokens"}) BACKGROUND_POLL = {"internal_call_origin": "background_response_cost_poll"} RESPONSE_OBJ = {"id": "resp_lit5602", "model": "gpt-4o", "usage": USAGE} + BACKGROUND_RESPONSE_OBJ = {**RESPONSE_OBJ, "background": True} def _kwargs(self, call_type, litellm_metadata=None): return { @@ -6369,25 +6370,36 @@ class TestOpenTelemetryNonInferenceUsage(unittest.TestCase): "standard_logging_object": {"id": "lit5602", "call_type": call_type, "metadata": {}}, } - def _token_attributes_on_span(self, call_type, litellm_metadata=None): + def _token_attributes_on_span(self, call_type, litellm_metadata=None, response_obj=None): otel = OpenTelemetry() mock_span = MagicMock() otel.set_attributes( span=mock_span, kwargs=self._kwargs(call_type, litellm_metadata), - response_obj=dict(self.RESPONSE_OBJ), + response_obj=response_obj or dict(self.RESPONSE_OBJ), ) return {call[0][0] for call in mock_span.set_attribute.call_args_list if call[0][0] in self.TOKEN_KEYS} - def _token_histogram_calls(self, call_type, litellm_metadata=None): + def _token_histogram_calls(self, call_type, litellm_metadata=None, response_obj=None): otel = OpenTelemetry() otel._operation_duration_histogram = MagicMock() otel._token_usage_histogram = MagicMock() otel._cost_histogram = None now = datetime.now() - otel._record_metrics(self._kwargs(call_type, litellm_metadata), dict(self.RESPONSE_OBJ), now, now) + otel._record_metrics( + self._kwargs(call_type, litellm_metadata), response_obj or dict(self.RESPONSE_OBJ), now, now + ) return otel._token_usage_histogram.record.call_count + def _time_per_output_token_calls(self, call_type, litellm_metadata=None, response_obj=None): + otel = OpenTelemetry() + otel._time_per_output_token_histogram = MagicMock() + now = datetime.now() + otel._record_time_per_output_token_metric( + self._kwargs(call_type, litellm_metadata), response_obj or dict(self.RESPONSE_OBJ), now, 1.0, {} + ) + return otel._time_per_output_token_histogram.record.call_count + def test_inference_call_still_reports_its_tokens_on_the_span(self): self.assertEqual(self._token_attributes_on_span("acompletion"), set(self.TOKEN_KEYS)) @@ -6405,3 +6417,23 @@ class TestOpenTelemetryNonInferenceUsage(unittest.TestCase): def test_background_cost_poll_read_still_records_the_token_usage_histogram(self): self.assertEqual(self._token_histogram_calls("aget_responses", self.BACKGROUND_POLL), 2) + + def test_background_response_read_still_reports_its_tokens_on_the_span(self): + self.assertEqual( + self._token_attributes_on_span("aget_responses", response_obj=self.BACKGROUND_RESPONSE_OBJ), + set(self.TOKEN_KEYS), + ) + + def test_background_response_read_still_records_the_token_usage_histogram(self): + self.assertEqual(self._token_histogram_calls("aget_responses", response_obj=self.BACKGROUND_RESPONSE_OBJ), 2) + + def test_inference_call_still_records_time_per_output_token(self): + self.assertEqual(self._time_per_output_token_calls("acompletion"), 1) + + def test_response_read_does_not_divide_its_latency_by_the_retrieved_token_count(self): + self.assertEqual(self._time_per_output_token_calls("aget_responses"), 0) + + def test_background_response_read_still_records_time_per_output_token(self): + self.assertEqual( + self._time_per_output_token_calls("aget_responses", response_obj=self.BACKGROUND_RESPONSE_OBJ), 1 + ) diff --git a/tests/test_litellm/litellm_core_utils/test_litellm_logging.py b/tests/test_litellm/litellm_core_utils/test_litellm_logging.py index 542617cc159..e106f4a1d98 100644 --- a/tests/test_litellm/litellm_core_utils/test_litellm_logging.py +++ b/tests/test_litellm/litellm_core_utils/test_litellm_logging.py @@ -4857,7 +4857,7 @@ class TestNonInferenceCallTypesAreNotBilled: ) return obj - def _retrieved_response(self): + def _retrieved_response(self, background: bool | None = None): from litellm.types.llms.openai import ResponsesAPIResponse return ResponsesAPIResponse( @@ -4866,6 +4866,7 @@ class TestNonInferenceCallTypesAreNotBilled: model="gpt-4o", output=[], usage=self.RETRIEVED_RESPONSE_USAGE, + background=background, ) def test_creating_a_response_is_still_priced(self): @@ -4953,6 +4954,47 @@ class TestNonInferenceCallTypesAreNotBilled: assert payload is not None assert payload["total_tokens"] == 6000 + def test_reading_a_background_response_is_still_priced(self): + """A background create answers queued with no usage at all, so whoever reads the finished + job is the first and only caller to see its tokens. Zeroing that read bills the job nothing.""" + cost = self._logging_obj("aget_responses")._response_cost_calculator( + result=self._retrieved_response(background=True) + ) + assert cost is not None and cost > 0 + + def test_reading_a_background_response_reports_usage_in_standard_logging_payload(self): + from datetime import datetime + + from litellm.litellm_core_utils.litellm_logging import ( + get_standard_logging_object_payload, + ) + + now = datetime.now() + payload = get_standard_logging_object_payload( + kwargs={ + "litellm_call_id": "lit5602-background-payload", + "model": "gpt-4o", + "call_type": "aget_responses", + "litellm_params": {}, + }, + init_response_obj=self._retrieved_response(background=True), + start_time=now, + end_time=now, + logging_obj=self._logging_obj("aget_responses"), + status="success", + ) + + assert payload is not None + assert payload["total_tokens"] == 6000 + + def test_reading_a_foreground_response_is_still_free(self): + """Guards the test above against a blanket exemption: an explicit background=false read was + already billed by its create and must stay at zero.""" + cost = self._logging_obj("aget_responses")._response_cost_calculator( + result=self._retrieved_response(background=False) + ) + assert cost == 0.0 + def _read_call_messages(self): logging_obj, _ = litellm.utils.function_setup( original_function="aget_responses", diff --git a/tests/test_litellm/proxy/spend_tracking/test_spend_tracking_utils.py b/tests/test_litellm/proxy/spend_tracking/test_spend_tracking_utils.py index fc9632e5723..f00160edae8 100644 --- a/tests/test_litellm/proxy/spend_tracking/test_spend_tracking_utils.py +++ b/tests/test_litellm/proxy/spend_tracking/test_spend_tracking_utils.py @@ -3275,7 +3275,9 @@ def test_user_traffic_carries_no_internal_call_origin(): assert metadata["internal_call_origin"] is None -def _spend_log_for_call_type(call_type: str, internal_call_origin: str | None = None) -> dict: +def _spend_log_for_call_type( + call_type: str, internal_call_origin: str | None = None, background: bool | None = None +) -> dict: from litellm.types.llms.openai import ResponsesAPIResponse return cast( @@ -3298,6 +3300,7 @@ def _spend_log_for_call_type(call_type: str, internal_call_origin: str | None = model="gpt-4o", output=[], usage={"input_tokens": 4000, "output_tokens": 2000, "total_tokens": 6000}, + background=background, ), start_time=datetime.datetime.now(timezone.utc), end_time=datetime.datetime.now(timezone.utc), @@ -3324,6 +3327,23 @@ def test_spend_log_for_background_response_cost_poll_counts_tokens(): assert payload["total_tokens"] == 6000 +def test_spend_log_for_background_response_retrieval_counts_tokens(): + """A background create answers queued carrying no usage, so its retrieval is the first and only + place the job's tokens are ever visible. Zeroing that read bills the whole job nothing on any + proxy that is not running the enterprise cost poller.""" + payload = _spend_log_for_call_type("aget_responses", background=True) + + assert payload["total_tokens"] == 6000 + + +def test_spend_log_for_foreground_response_retrieval_still_counts_nothing(): + """Guards the test above against a blanket exemption: an explicit background=false read was + already billed by its create and must stay at zero.""" + payload = _spend_log_for_call_type("aget_responses", background=False) + + assert payload["total_tokens"] == 0 + + def test_spend_log_for_response_creation_still_counts_tokens(): """Guards the test above: the same response object must still be counted on the create path.""" payload = _spend_log_for_call_type("aresponses")