From 737a36558c0cb2b545ccee5e019e71a51b41975e Mon Sep 17 00:00:00 2001 From: Krrish Dholakia Date: Sat, 16 Aug 2025 15:42:30 -0700 Subject: [PATCH] feat(llm_http_handler.py): add OTEL tracing for actual llm api call detailed latency tracing --- litellm/litellm_core_utils/logging_utils.py | 119 +++++++++++++++++- litellm/llms/custom_httpx/http_handler.py | 26 ++-- litellm/llms/custom_httpx/llm_http_handler.py | 58 +++++---- .../llms/openai/chat/gpt_transformation.py | 2 + litellm/main.py | 4 + litellm/proxy/_new_secret_config.yaml | 1 + 6 files changed, 170 insertions(+), 40 deletions(-) diff --git a/litellm/litellm_core_utils/logging_utils.py b/litellm/litellm_core_utils/logging_utils.py index c7512ea146..bf43519afc 100644 --- a/litellm/litellm_core_utils/logging_utils.py +++ b/litellm/litellm_core_utils/logging_utils.py @@ -1,5 +1,6 @@ import asyncio import functools +import time from datetime import datetime from typing import TYPE_CHECKING, Any, List, Optional, Union @@ -11,15 +12,19 @@ from litellm.types.utils import ( ) if TYPE_CHECKING: + from opentelemetry.trace import Span as _Span + from litellm import ModelResponse as _ModelResponse from litellm.litellm_core_utils.litellm_logging import ( Logging as LiteLLMLoggingObject, ) LiteLLMModelResponse = _ModelResponse + Span = Union[_Span, Any] else: LiteLLMModelResponse = Any LiteLLMLoggingObject = Any + Span = Any import litellm @@ -28,9 +33,52 @@ import litellm Helper utils used for logging callbacks """ +# Global service logger instance to avoid recreating it +_service_logger = None + + +def _get_service_logger(): + """Get or create the global ServiceLogging instance""" + global _service_logger + if _service_logger is None: + from litellm._service_logger import ServiceLogging + + _service_logger = ServiceLogging() + return _service_logger + + +def _get_parent_otel_span_from_logging_obj( + logging_obj: Optional[LiteLLMLoggingObject] = None, +) -> Optional[Span]: + """ + Extract the parent OTEL span from the logging object using existing helper. + + Args: + logging_obj: The LiteLLM logging object containing model call details + + Returns: + The parent OTEL span if found, None otherwise + """ + try: + if logging_obj is None or not hasattr(logging_obj, "model_call_details"): + return None + + # Reuse existing function by passing model_call_details as kwargs + from litellm.litellm_core_utils.core_helpers import ( + _get_parent_otel_span_from_kwargs, + ) + + return _get_parent_otel_span_from_kwargs(logging_obj.model_call_details) + + except Exception as e: + verbose_logger.exception( + f"Error in _get_parent_otel_span_from_logging_obj: {str(e)}" + ) + return None + def convert_litellm_response_object_to_str( - response_obj: Union[Any, LiteLLMModelResponse] + response_obj: Union[Any, LiteLLMModelResponse], ) -> Optional[str]: """ Get the string of the response object from LiteLLM @@ -125,37 +173,102 @@ def track_llm_api_timing(): """ Decorator to track LLM API call timing for both sync and async functions. The logging_obj is expected to be passed as an argument to the decorated function. + Logs timing using ServiceLogging similar to Redis cache. """ def decorator(func): @functools.wraps(func) async def async_wrapper(*args, **kwargs): start_time = datetime.now() + start_time_float = time.time() + logging_obj = kwargs.get("logging_obj", None) + + # Extract parent OTEL span from logging object + parent_otel_span = _get_parent_otel_span_from_logging_obj(logging_obj) + try: result = await func(*args, **kwargs) return result finally: end_time = datetime.now() + end_time_float = time.time() + duration = end_time_float - start_time_float + + # Set duration in model call details _set_duration_in_model_call_details( - logging_obj=kwargs.get("logging_obj", None), + logging_obj=logging_obj, start_time=start_time, end_time=end_time, ) + # Log timing using ServiceLogging (like Redis cache) + try: + from litellm.types.services import ServiceTypes + + service_logger = _get_service_logger() + + # Get function name for call_type + call_type = f"{func.__name__} <- track_llm_api_timing" + + # Create async task for service logging (similar to Redis cache pattern) + asyncio.create_task( + service_logger.async_service_success_hook( + service=ServiceTypes.LITELLM, + duration=duration, + call_type=call_type, + start_time=start_time_float, + end_time=end_time_float, + parent_otel_span=parent_otel_span, + ) + ) + except Exception as e: + verbose_logger.debug(f"Error in service logging: {str(e)}") + @functools.wraps(func) def sync_wrapper(*args, **kwargs): start_time = datetime.now() + start_time_float = time.time() + logging_obj = kwargs.get("logging_obj", None) + + # Extract parent OTEL span from logging object + parent_otel_span = _get_parent_otel_span_from_logging_obj(logging_obj) + try: result = func(*args, **kwargs) return result finally: end_time = datetime.now() + end_time_float = time.time() + duration = end_time_float - start_time_float + + # Set duration in model call details _set_duration_in_model_call_details( - logging_obj=kwargs.get("logging_obj", None), + logging_obj=logging_obj, start_time=start_time, end_time=end_time, ) + # Log timing using ServiceLogging (like Redis cache) + try: + from litellm.types.services import ServiceTypes + + service_logger = _get_service_logger() + + # Get function name for call_type + call_type = f"{func.__name__} <- track_llm_api_timing" + + # Use sync service logging for sync functions + service_logger.service_success_hook( + service=ServiceTypes.LITELLM, + duration=duration, + call_type=call_type, + start_time=start_time_float, + end_time=end_time_float, + parent_otel_span=parent_otel_span, + ) + except Exception as e: + verbose_logger.debug(f"Error in service logging: {str(e)}") + # Check if the function is async or sync if asyncio.iscoroutinefunction(func): return async_wrapper diff --git a/litellm/llms/custom_httpx/http_handler.py b/litellm/llms/custom_httpx/http_handler.py index cf2187153a..4d8781fff2 100644 --- a/litellm/llms/custom_httpx/http_handler.py +++ b/litellm/llms/custom_httpx/http_handler.py @@ -40,7 +40,9 @@ headers = { _DEFAULT_TIMEOUT = httpx.Timeout(timeout=5.0, connect=5.0) -def get_ssl_configuration(ssl_verify: Optional[VerifyTypes] = None) -> Union[bool, str, ssl.SSLContext]: +def get_ssl_configuration( + ssl_verify: Optional[VerifyTypes] = None, +) -> Union[bool, str, ssl.SSLContext]: """ Unified SSL configuration function that handles ssl_context and ssl_verify logic. @@ -59,7 +61,7 @@ def get_ssl_configuration(ssl_verify: Optional[VerifyTypes] = None) -> Union[boo - False: Disable SSL verification - True: Enable SSL verification - str: Path to CA bundle file - + Returns: Union[bool, str, ssl.SSLContext]: Appropriate SSL configuration """ @@ -72,7 +74,9 @@ def get_ssl_configuration(ssl_verify: Optional[VerifyTypes] = None) -> Union[boo # Get ssl_verify from environment or litellm settings if not provided if ssl_verify is None: ssl_verify = os.getenv("SSL_VERIFY", litellm.ssl_verify) - ssl_verify_bool = str_to_bool(ssl_verify) if isinstance(ssl_verify, str) else ssl_verify + ssl_verify_bool = ( + str_to_bool(ssl_verify) if isinstance(ssl_verify, str) else ssl_verify + ) if ssl_verify_bool is not None: ssl_verify = ssl_verify_bool @@ -89,14 +93,9 @@ def get_ssl_configuration(ssl_verify: Optional[VerifyTypes] = None) -> Union[boo cafile = certifi.where() if ssl_verify is not False: - custom_ssl_context = ssl.create_default_context( - cafile=cafile - ) + custom_ssl_context = ssl.create_default_context(cafile=cafile) # If security level is set, apply it to the SSL context - if ( - ssl_security_level - and isinstance(ssl_security_level, str) - ): + if ssl_security_level and isinstance(ssl_security_level, str): # Create a custom SSL context with reduced security level custom_ssl_context.set_ciphers(ssl_security_level) @@ -260,6 +259,7 @@ class AsyncHTTPHandler: files: Optional[RequestFiles] = None, content: Any = None, ): + start_time = time.time() try: if timeout is None: @@ -586,7 +586,7 @@ class AsyncHTTPHandler: ) -> Dict[str, Any]: """ Helper method to get SSL connector initialization arguments for aiohttp TCPConnector. - + SSL Configuration Priority: 1. If ssl_context is provided -> use the custom SSL context 2. If ssl_verify is False -> disable SSL verification (ssl=False) @@ -597,14 +597,14 @@ class AsyncHTTPHandler: connector_kwargs: Dict[str, Any] = { "local_addr": ("0.0.0.0", 0) if litellm.force_ipv4 else None, } - + if ssl_context is not None: # Priority 1: Use the provided custom SSL context connector_kwargs["ssl"] = ssl_context elif ssl_verify is False: # Priority 2: Explicitly disable SSL verification connector_kwargs["verify_ssl"] = False - + return connector_kwargs @staticmethod diff --git a/litellm/llms/custom_httpx/llm_http_handler.py b/litellm/llms/custom_httpx/llm_http_handler.py index 3e7dff9182..c9d70088d0 100644 --- a/litellm/llms/custom_httpx/llm_http_handler.py +++ b/litellm/llms/custom_httpx/llm_http_handler.py @@ -111,6 +111,7 @@ class BaseLLMHTTPHandler: response: Optional[httpx.Response] = None for i in range(max(max_retry_on_unprocessable_entity_error, 1)): try: + response = await async_httpx_client.post( url=api_base, headers=headers, @@ -2712,7 +2713,8 @@ class BaseLLMHTTPHandler: headers = image_generation_provider_config.validate_environment( api_key=litellm_params.get("api_key", None), - headers=image_generation_optional_request_params.get("extra_headers", {}) or {}, + headers=image_generation_optional_request_params.get("extra_headers", {}) + or {}, model=model, messages=[], optional_params=image_generation_optional_request_params, @@ -2763,15 +2765,17 @@ class BaseLLMHTTPHandler: provider_config=image_generation_provider_config, ) - model_response: ImageResponse = image_generation_provider_config.transform_image_generation_response( - model=model, - raw_response=response, - model_response=litellm.ImageResponse(), - logging_obj=logging_obj, - request_data=data, - optional_params=image_generation_optional_request_params, - litellm_params=dict(litellm_params), - encoding=None, + model_response: ImageResponse = ( + image_generation_provider_config.transform_image_generation_response( + model=model, + raw_response=response, + model_response=litellm.ImageResponse(), + logging_obj=logging_obj, + request_data=data, + optional_params=image_generation_optional_request_params, + litellm_params=dict(litellm_params), + encoding=None, + ) ) return model_response @@ -2804,10 +2808,10 @@ class BaseLLMHTTPHandler: else: async_httpx_client = client - headers = image_generation_provider_config.validate_environment( api_key=litellm_params.get("api_key", None), - headers=image_generation_optional_request_params.get("extra_headers", {}) or {}, + headers=image_generation_optional_request_params.get("extra_headers", {}) + or {}, model=model, messages=[], optional_params=image_generation_optional_request_params, @@ -2858,17 +2862,19 @@ class BaseLLMHTTPHandler: provider_config=image_generation_provider_config, ) - model_response: ImageResponse = image_generation_provider_config.transform_image_generation_response( - model=model, - raw_response=response, - model_response=litellm.ImageResponse(), - logging_obj=logging_obj, - request_data=data, - optional_params=image_generation_optional_request_params, - litellm_params=dict(litellm_params), - encoding=None, + model_response: ImageResponse = ( + image_generation_provider_config.transform_image_generation_response( + model=model, + raw_response=response, + model_response=litellm.ImageResponse(), + logging_obj=logging_obj, + request_data=data, + optional_params=image_generation_optional_request_params, + litellm_params=dict(litellm_params), + encoding=None, + ) ) - + return model_response ###### VECTOR STORE HANDLER ###### @@ -2936,7 +2942,9 @@ class BaseLLMHTTPHandler: }, ) - request_data = json.dumps(request_body) if signed_json_body is None else signed_json_body + request_data = ( + json.dumps(request_body) if signed_json_body is None else signed_json_body + ) try: response = await async_httpx_client.post( @@ -3035,7 +3043,9 @@ class BaseLLMHTTPHandler: }, ) - request_data = json.dumps(request_body) if signed_json_body is None else signed_json_body + request_data = ( + json.dumps(request_body) if signed_json_body is None else signed_json_body + ) try: response = sync_httpx_client.post( diff --git a/litellm/llms/openai/chat/gpt_transformation.py b/litellm/llms/openai/chat/gpt_transformation.py index 396d59145f..f043ef4052 100644 --- a/litellm/llms/openai/chat/gpt_transformation.py +++ b/litellm/llms/openai/chat/gpt_transformation.py @@ -428,6 +428,8 @@ class OpenAIGPTConfig(BaseLLMModelInfo, BaseConfig): if tools is not None and len(tools) > 0: optional_params["tools"] = tools + optional_params.pop("max_retries", None) + return { "model": model, "messages": messages, diff --git a/litellm/main.py b/litellm/main.py index 4a8f82e114..dadcdfbb6b 100644 --- a/litellm/main.py +++ b/litellm/main.py @@ -1562,6 +1562,7 @@ def completion( # type: ignore # noqa: PLR0915 ) elif custom_llm_provider == "deepseek": ## COMPLETION CALL + try: response = base_llm_http_handler.completion( model=model, @@ -1593,6 +1594,7 @@ def completion( # type: ignore # noqa: PLR0915 elif custom_llm_provider == "azure_ai": from litellm.llms.azure_ai.common_utils import AzureFoundryModelInfo + api_base = AzureFoundryModelInfo.get_api_base(api_base) # set API KEY api_key = AzureFoundryModelInfo.get_api_key(api_key) @@ -1976,8 +1978,10 @@ def completion( # type: ignore # noqa: PLR0915 use_base_llm_http_handler = get_secret_bool( "EXPERIMENTAL_OPENAI_BASE_LLM_HTTP_HANDLER" ) + try: if use_base_llm_http_handler: + response = base_llm_http_handler.completion( model=model, messages=messages, diff --git a/litellm/proxy/_new_secret_config.yaml b/litellm/proxy/_new_secret_config.yaml index b48fe5be1c..99460a0547 100644 --- a/litellm/proxy/_new_secret_config.yaml +++ b/litellm/proxy/_new_secret_config.yaml @@ -6,6 +6,7 @@ model_list: api_base: https://exampleopenaiendpoint-production.up.railway.app/ litellm_settings: + callbacks: ["otel"] cache: true cache_params: type: redis