From dde4042e2dcf169194ccd13a739278ff5a9e5770 Mon Sep 17 00:00:00 2001 From: Krish Dholakia Date: Sat, 7 Mar 2026 19:24:36 -0800 Subject: [PATCH] System performance bottlenecks (#23075) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * perf: address GIL contention and hot-path bottlenecks from profiling data Based on py-spy GIL profiling (38,800 samples, 2000 concurrent users) and pyinstrument per-request timing, this commit addresses the top performance bottlenecks identified: 1. _sanitize_request_body_for_spend_logs_payload (2.9% GIL): - Remove redundant inner import (constants already imported at top-level) - Remove dead-code branch (len check after already confirmed len > max) - Pre-compute truncation ratios outside inner function - Reorder isinstance checks: str first (most common leaf type) 2. Pydantic repr in logging (2.3% GIL): - Guard print_deployment calls behind isEnabledFor(logging.INFO) - Replace copy.deepcopy with shallow dict() copy in print_deployment - Use %-style lazy formatting instead of f-strings for logger calls - Remove kwargs from prometheus debug log message 3. Prometheus label_factory overhead (1.5% + 0.7% GIL): - Cache model_dump() on UserAPIKeyLabelValues via get_label_dict() - Convert supported_enum_labels to frozenset for O(1) membership tests - Called 37 times per success event; caching avoids 36 redundant dumps 4. pre_call_utils header lookup (1.9% GIL): - Replace dict comprehension over all headers with early-exit loop - Only lowercase and compare the two target header names 5. safe_json_dumps (0.7% GIL): - Replace stdlib json.dumps with orjson.dumps for final serialization 6. Hot-path debug logging: - Convert f-string debug logs to %-style in litellm_logging.py - Simplify prometheus print_verbose call 7. Cost calculator annotation checks: - Optimize response_includes_annotation_type to handle both dict and object annotation types without repeated __getattr__ calls Estimated GIL time reduction: ~11-12% under concurrency. Co-authored-by: Krish Dholakia * test: add locust benchmark comparison tooling for perf analysis Adds: - loadtest_config_perf.yaml: proxy config with spend_logs enabled - locustfile_perf.py: locust scenario for perf comparison - compare_perf_results.py: CSV parser + comparison report generator - run_perf_comparison.sh: automated baseline vs optimized runner Co-authored-by: Krish Dholakia * perf: guard orjson import with fallback, pre-parse httpx URLs, fix docstring Addresses three review concerns and adds httpx URL caching: 1. safe_json_dumps.py: Guard orjson import with try/except fallback to stdlib json. This module is on the core SDK import path via _logging.py — unconditional orjson import would break plain 'pip install litellm' (non-proxy) users. 2. router.py print_deployment: Update docstring to accurately describe the reduced return shape (model_name + litellm_params only). 3. run_perf_comparison.sh: Fix locustfile reference to use the correct locustfile_perf.py instead of locustfile.py. 4. httpx URL pre-parsing (~7.8us -> ~0.4us per request, 19x speedup): Add _parse_url() with LRU cache (maxsize=64) that pre-parses URL strings into httpx.URL objects. Applied to all HTTP methods (GET, POST, PUT, PATCH, DELETE) in both AsyncHTTPHandler and HTTPHandler. Eliminates regex-heavy re.finditer inside httpx._urlparse on every request — confirmed as a GIL hotspot in py-spy thread dumps. Co-authored-by: Krish Dholakia * fix: address review - document _parse_url safety, guard print_verbose 1. http_handler.py _parse_url: Add docstring documenting why the LRU cache is safe with query-string URLs. When params= is non-None, httpx replaces the query string entirely; when params= is None, the cached URL preserves the original query string. Both match pre-optimization behavior (verified with httpx.URL vs str tests). 2. prometheus.py print_verbose: Guard the call behind litellm.set_verbose check so the string formatting is truly lazy. The previous % formatting was eagerly evaluated (same cost as f-string) since print_verbose takes a pre-formatted string. Co-authored-by: Krish Dholakia --------- Co-authored-by: Cursor Agent --- litellm/integrations/prometheus.py | 21 ++- litellm/litellm_core_utils/litellm_logging.py | 2 +- .../llm_cost_calc/tool_call_cost_tracking.py | 11 +- litellm/litellm_core_utils/safe_json_dumps.py | 15 +- litellm/llms/custom_httpx/http_handler.py | 51 +++++-- litellm/proxy/litellm_pre_call_utils.py | 13 +- .../spend_tracking/spend_tracking_utils.py | 56 ++----- litellm/router.py | 66 ++++++--- litellm/router_strategy/simple_shuffle.py | 11 +- litellm/types/integrations/prometheus.py | 10 +- tests/load_tests/compare_perf_results.py | 135 +++++++++++++++++ tests/load_tests/loadtest_config_perf.yaml | 17 +++ tests/load_tests/locustfile_perf.py | 23 +++ tests/load_tests/run_perf_comparison.sh | 138 ++++++++++++++++++ 14 files changed, 461 insertions(+), 108 deletions(-) create mode 100644 tests/load_tests/compare_perf_results.py create mode 100644 tests/load_tests/loadtest_config_perf.yaml create mode 100644 tests/load_tests/locustfile_perf.py create mode 100755 tests/load_tests/run_perf_comparison.sh diff --git a/litellm/integrations/prometheus.py b/litellm/integrations/prometheus.py index 7a08432b9a1..c8f5a303770 100644 --- a/litellm/integrations/prometheus.py +++ b/litellm/integrations/prometheus.py @@ -887,7 +887,7 @@ class PrometheusLogger(CustomLogger): from litellm.types.utils import StandardLoggingPayload verbose_logger.debug( - f"prometheus Logging - Enters success logging function for kwargs {kwargs}" + "prometheus Logging - Enters success logging function" ) # unpack kwargs @@ -943,9 +943,10 @@ class PrometheusLogger(CustomLogger): else: _tags = [] - print_verbose( - f"inside track_prometheus_metrics, model {model}, response_cost {response_cost}, tokens_used {tokens_used}, end_user_id {end_user_id}, user_api_key {user_api_key}" - ) + if litellm.set_verbose: + print_verbose( + f"inside track_prometheus_metrics, model {model}, response_cost {response_cost}, tokens_used {tokens_used}" + ) enum_values = UserAPIKeyLabelValues( end_user=end_user_id, @@ -3056,15 +3057,13 @@ def prometheus_label_factory( Ensures end_user param is not sent to prometheus if it is not supported. """ - # Extract dictionary from Pydantic object - enum_dict = enum_values.model_dump() + enum_dict = enum_values.get_label_dict() - # Filter supported labels and sanitize values to prevent breaking - # the Prometheus text format (e.g. U+2028 Line Separator in label values) + supported_set = frozenset(supported_enum_labels) if not isinstance(supported_enum_labels, (set, frozenset)) else supported_enum_labels filtered_labels = { label: _sanitize_prometheus_label_value(value) for label, value in enum_dict.items() - if label in supported_enum_labels + if label in supported_set } if UserAPIKeyLabelNames.END_USER.value in filtered_labels: @@ -3079,14 +3078,14 @@ def prometheus_label_factory( for key, value in enum_values.custom_metadata_labels.items(): # check sanitized key sanitized_key = _sanitize_prometheus_label_name(key) - if sanitized_key in supported_enum_labels: + if sanitized_key in supported_set: filtered_labels[sanitized_key] = _sanitize_prometheus_label_value(value) # Add custom tags if configured if enum_values.tags is not None: custom_tag_labels = get_custom_labels_from_tags(enum_values.tags) for key, value in custom_tag_labels.items(): - if key in supported_enum_labels: + if key in supported_set: filtered_labels[key] = _sanitize_prometheus_label_value(value) for label in supported_enum_labels: diff --git a/litellm/litellm_core_utils/litellm_logging.py b/litellm/litellm_core_utils/litellm_logging.py index 6f587abcdf1..6c2dabc9411 100644 --- a/litellm/litellm_core_utils/litellm_logging.py +++ b/litellm/litellm_core_utils/litellm_logging.py @@ -1476,7 +1476,7 @@ class Logging(LiteLLMLoggingBaseClass): **response_cost_calculator_kwargs ) - verbose_logger.debug(f"response_cost: {response_cost}") + verbose_logger.debug("response_cost: %s", response_cost) return response_cost except Exception as e: # error calculating cost debug_info = StandardLoggingModelCostFailureDebugInformation( diff --git a/litellm/litellm_core_utils/llm_cost_calc/tool_call_cost_tracking.py b/litellm/litellm_core_utils/llm_cost_calc/tool_call_cost_tracking.py index 4a4a2508d2e..0fd472c02ad 100644 --- a/litellm/litellm_core_utils/llm_cost_calc/tool_call_cost_tracking.py +++ b/litellm/litellm_core_utils/llm_cost_calc/tool_call_cost_tracking.py @@ -387,11 +387,12 @@ class StandardBuiltInToolCostTracking: message: Optional[Message] = getattr(choice, "message", None) if message is None: continue - if annotations := getattr(message, "annotations", None): - if len(annotations) > 0: - for annotation in annotations: - if annotation.get("type", None) == annotation_type: - return True + annotations = getattr(message, "annotations", None) + if annotations: + for annotation in annotations: + _type = annotation.get("type") if isinstance(annotation, dict) else getattr(annotation, "type", None) + if _type == annotation_type: + return True return False @staticmethod diff --git a/litellm/litellm_core_utils/safe_json_dumps.py b/litellm/litellm_core_utils/safe_json_dumps.py index 051aa2f27a5..bd19583bfac 100644 --- a/litellm/litellm_core_utils/safe_json_dumps.py +++ b/litellm/litellm_core_utils/safe_json_dumps.py @@ -5,6 +5,13 @@ from pydantic import BaseModel from litellm.constants import DEFAULT_MAX_RECURSE_DEPTH +try: + import orjson + + _has_orjson = True +except ImportError: + _has_orjson = False + def safe_dumps(data: Any, max_depth: int = DEFAULT_MAX_RECURSE_DEPTH) -> str: """ @@ -13,13 +20,10 @@ def safe_dumps(data: Any, max_depth: int = DEFAULT_MAX_RECURSE_DEPTH) -> str: """ def _serialize(obj: Any, seen: set, depth: int) -> Any: - # Check for maximum depth. if depth > max_depth: return "MaxDepthExceeded" - # Base-case: if it is a primitive, simply return it. if isinstance(obj, (str, int, float, bool, type(None))): return obj - # Check for circular reference. if id(obj) in seen: return "CircularReference Detected" seen.add(id(obj)) @@ -27,7 +31,7 @@ def safe_dumps(data: Any, max_depth: int = DEFAULT_MAX_RECURSE_DEPTH) -> str: if isinstance(obj, dict): result = {} for k, v in obj.items(): - if isinstance(k, (str)): + if isinstance(k, str): result[k] = _serialize(v, seen, depth + 1) seen.remove(id(obj)) return result @@ -49,11 +53,12 @@ def safe_dumps(data: Any, max_depth: int = DEFAULT_MAX_RECURSE_DEPTH) -> str: seen.remove(id(obj)) return result else: - # Fall back to string conversion for non-serializable objects. try: return str(obj) except Exception: return "Unserializable Object" safe_data = _serialize(data, set(), 0) + if _has_orjson: + return orjson.dumps(safe_data, default=str).decode() return json.dumps(safe_data, default=str) diff --git a/litellm/llms/custom_httpx/http_handler.py b/litellm/llms/custom_httpx/http_handler.py index 7847e9f9d5c..69dc0175585 100644 --- a/litellm/llms/custom_httpx/http_handler.py +++ b/litellm/llms/custom_httpx/http_handler.py @@ -1,4 +1,5 @@ import asyncio +import functools import os import ssl import sys @@ -51,6 +52,21 @@ try: except Exception: version = "0.0.0" + +@functools.lru_cache(maxsize=64) +def _parse_url(url: str) -> httpx.URL: + """Pre-parse a URL string into an httpx.URL to avoid regex-heavy + parsing inside httpx._merge_url on every request (~7μs → ~0.4μs). + + Safe to use with ``build_request(params=...)``: httpx replaces the + query string entirely when ``params`` is non-None, so any query + params baked into the cached URL are harmless in that case. When + ``params`` is None the cached URL preserves the original query + string, which is the correct behaviour. + """ + return httpx.URL(url) + + def get_default_headers() -> dict: """ Get default headers for HTTP requests. @@ -424,7 +440,7 @@ class AsyncHTTPHandler: params.update(HTTPHandler.extract_query_params(url)) response = await self.client.get( - url, params=params, headers=headers, follow_redirects=_follow_redirects # type: ignore + _parse_url(url), params=params, headers=headers, follow_redirects=_follow_redirects # type: ignore ) return response @@ -452,9 +468,10 @@ class AsyncHTTPHandler: data, content ) + parsed_url = _parse_url(url) req = self.client.build_request( "POST", - url, + parsed_url, data=request_data, json=json, params=params, @@ -533,7 +550,7 @@ class AsyncHTTPHandler: ) req = self.client.build_request( - "PUT", url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore + "PUT", _parse_url(url), data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore ) response = await self.client.send(req) response.raise_for_status() @@ -599,7 +616,7 @@ class AsyncHTTPHandler: ) req = self.client.build_request( - "PATCH", url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore + "PATCH", _parse_url(url), data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore ) response = await self.client.send(req) response.raise_for_status() @@ -665,7 +682,7 @@ class AsyncHTTPHandler: ) req = self.client.build_request( - "DELETE", url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore + "DELETE", _parse_url(url), data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore ) response = await self.client.send(req, stream=stream) response.raise_for_status() @@ -717,7 +734,7 @@ class AsyncHTTPHandler: request_data, request_content = _prepare_request_data_and_content(data, content) req = client.build_request( - "POST", url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore + "POST", _parse_url(url), data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore ) response = await client.send(req, stream=stream) response.raise_for_status() @@ -984,7 +1001,7 @@ class HTTPHandler: params.update(self.extract_query_params(url)) response = self.client.get( - url, + _parse_url(url), params=params, headers=headers, ) @@ -1023,10 +1040,11 @@ class HTTPHandler: data, content ) + parsed_url = _parse_url(url) if timeout is not None: req = self.client.build_request( "POST", - url, + parsed_url, data=request_data, # type: ignore json=json, params=params, @@ -1037,7 +1055,7 @@ class HTTPHandler: ) else: req = self.client.build_request( - "POST", url, data=request_data, json=json, params=params, headers=headers, files=files, content=request_content # type: ignore + "POST", parsed_url, data=request_data, json=json, params=params, headers=headers, files=files, content=request_content # type: ignore ) response = self.client.send(req, stream=stream) response.raise_for_status() @@ -1079,13 +1097,14 @@ class HTTPHandler: data, content ) + parsed_url = _parse_url(url) if timeout is not None: req = self.client.build_request( - "PATCH", url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore + "PATCH", parsed_url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore ) else: req = self.client.build_request( - "PATCH", url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore + "PATCH", parsed_url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore ) response = self.client.send(req, stream=stream) response.raise_for_status() @@ -1128,13 +1147,14 @@ class HTTPHandler: data, content ) + parsed_url = _parse_url(url) if timeout is not None: req = self.client.build_request( - "PUT", url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore + "PUT", parsed_url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore ) else: req = self.client.build_request( - "PUT", url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore + "PUT", parsed_url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore ) response = self.client.send(req, stream=stream) return response @@ -1164,13 +1184,14 @@ class HTTPHandler: data, content ) + parsed_url = _parse_url(url) if timeout is not None: req = self.client.build_request( - "DELETE", url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore + "DELETE", parsed_url, data=request_data, json=json, params=params, headers=headers, timeout=timeout, content=request_content # type: ignore ) else: req = self.client.build_request( - "DELETE", url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore + "DELETE", parsed_url, data=request_data, json=json, params=params, headers=headers, content=request_content # type: ignore ) response = self.client.send(req, stream=stream) response.raise_for_status() diff --git a/litellm/proxy/litellm_pre_call_utils.py b/litellm/proxy/litellm_pre_call_utils.py index ee97960c0a2..37c80879073 100644 --- a/litellm/proxy/litellm_pre_call_utils.py +++ b/litellm/proxy/litellm_pre_call_utils.py @@ -102,10 +102,15 @@ def get_chain_id_from_headers(headers: Optional[Dict[str, str]]) -> Optional[str """ if not headers: return None - normalized = {k.lower(): v for k, v in headers.items() if isinstance(k, str)} - return normalized.get("x-litellm-trace-id") or normalized.get( - "x-litellm-session-id" - ) + session_id = None + for k, v in headers.items(): + if isinstance(k, str): + k_lower = k.lower() + if k_lower == "x-litellm-trace-id": + return v + elif session_id is None and k_lower == "x-litellm-session-id": + session_id = v + return session_id def safe_add_api_version_from_query_params(data: dict, request: Request): diff --git a/litellm/proxy/spend_tracking/spend_tracking_utils.py b/litellm/proxy/spend_tracking/spend_tracking_utils.py index f381432a089..ef992b7299e 100644 --- a/litellm/proxy/spend_tracking/spend_tracking_utils.py +++ b/litellm/proxy/spend_tracking/spend_tracking_utils.py @@ -632,61 +632,37 @@ def _sanitize_request_body_for_spend_logs_payload( Recursively sanitize request body to prevent logging large base64 strings or other large values. Truncates strings longer than MAX_STRING_LENGTH_PROMPT_IN_DB characters and handles nested dictionaries. """ - from litellm.constants import ( - LITELLM_TRUNCATED_PAYLOAD_FIELD, - LITELLM_TRUNCATION_DB_SAFEGUARD_NOTE, - ) - if visited is None: visited = set() if max_string_length_prompt_in_db is None: max_string_length_prompt_in_db = _get_max_string_length_prompt_in_db() - # Get the object's memory address to track visited objects obj_id = id(request_body) if obj_id in visited: return {} visited.add(obj_id) + _max_len = max_string_length_prompt_in_db + _start_chars = int(_max_len * 0.35) + _end_chars = min(int(_max_len * 0.65), _max_len - _start_chars) + def _sanitize_value(value: Any) -> Any: - if isinstance(value, dict): + if isinstance(value, str): + if len(value) > _max_len: + skipped_chars = len(value) - _start_chars - _end_chars + return ( + f"{value[:_start_chars]}" + f"... ({LITELLM_TRUNCATED_PAYLOAD_FIELD} skipped {skipped_chars} chars. " + f"{LITELLM_TRUNCATION_DB_SAFEGUARD_NOTE}) ..." + f"{value[-_end_chars:]}" + ) + return value + elif isinstance(value, dict): return _sanitize_request_body_for_spend_logs_payload( - value, visited, max_string_length_prompt_in_db + value, visited, _max_len ) elif isinstance(value, list): return [_sanitize_value(item) for item in value] - elif isinstance(value, str): - if len(value) > max_string_length_prompt_in_db: - # Keep 35% from beginning and 65% from end (end is usually more important) - # This split ensures we keep more context from the end of conversations - start_ratio = 0.35 - end_ratio = 0.65 - - # Calculate character distribution - start_chars = int(max_string_length_prompt_in_db * start_ratio) - end_chars = int(max_string_length_prompt_in_db * end_ratio) - - # Ensure we don't exceed the total limit - total_keep = start_chars + end_chars - if total_keep > max_string_length_prompt_in_db: - end_chars = max_string_length_prompt_in_db - start_chars - - # If the string length is less than what we want to keep, just truncate normally - if len(value) <= max_string_length_prompt_in_db: - return value - - # Calculate how many characters are being skipped - skipped_chars = len(value) - total_keep - - # Build the truncated string: beginning + truncation marker + end - truncated_value = ( - f"{value[:start_chars]}" - f"... ({LITELLM_TRUNCATED_PAYLOAD_FIELD} skipped {skipped_chars} chars. " - f"{LITELLM_TRUNCATION_DB_SAFEGUARD_NOTE}) ..." - f"{value[-end_chars:]}" - ) - return truncated_value - return value return value return {k: _sanitize_value(v) for k, v in request_body.items()} diff --git a/litellm/router.py b/litellm/router.py index 7119d2e850d..a1eebf119cc 100644 --- a/litellm/router.py +++ b/litellm/router.py @@ -1314,24 +1314,30 @@ class Router: def print_deployment(self, deployment: dict): """ - returns a copy of the deployment with the api key masked + Returns a lightweight dict with model_name + litellm_params (api key masked). - Only returns 2 characters of the api key and masks the rest with * (10 *). + Only includes model_name and litellm_params to avoid deep-copying + the full deployment dict on every log call. """ try: - _deployment_copy = copy.deepcopy(deployment) - litellm_params: dict = _deployment_copy["litellm_params"] - + litellm_params: dict = deployment.get("litellm_params", {}) if litellm.redact_user_api_key_info: masker = SensitiveDataMasker(visible_prefix=2, visible_suffix=0) - _deployment_copy["litellm_params"] = masker.mask_dict(litellm_params) - elif "api_key" in litellm_params: - litellm_params["api_key"] = litellm_params["api_key"][:2] + "*" * 10 - - return _deployment_copy + masked_params = masker.mask_dict(dict(litellm_params)) + else: + masked_params = dict(litellm_params) + if "api_key" in masked_params: + api_key = masked_params["api_key"] + masked_params["api_key"] = ( + api_key[:2] + "*" * 10 if api_key else api_key + ) + return { + "model_name": deployment.get("model_name"), + "litellm_params": masked_params, + } except Exception as e: verbose_router_logger.debug( - f"Error occurred while printing deployment - {str(e)}" + "Error occurred while printing deployment - %s", str(e) ) raise e @@ -8925,9 +8931,13 @@ class Router: parent_otel_span=parent_otel_span, ) raise exception - verbose_router_logger.info( - f"get_available_deployment for model: {model}, Selected deployment: {self.print_deployment(deployment)} for model: {model}" - ) + if verbose_router_logger.isEnabledFor(logging.INFO): + verbose_router_logger.info( + "get_available_deployment for model: %s, Selected deployment: %s for model: %s", + model, + self.print_deployment(deployment), + model, + ) end_time = time.time() _duration = end_time - start_time @@ -9077,9 +9087,12 @@ class Router: ) raise exception - verbose_router_logger.info( - f"async_get_available_deployment_for_pass_through model: {model}, selected deployment: {self.print_deployment(deployment)}" - ) + if verbose_router_logger.isEnabledFor(logging.INFO): + verbose_router_logger.info( + "async_get_available_deployment_for_pass_through model: %s, selected deployment: %s", + model, + self.print_deployment(deployment), + ) end_time = time.perf_counter() _duration = end_time - start_time @@ -9268,9 +9281,13 @@ class Router: enable_pre_call_checks=self.enable_pre_call_checks, cooldown_list=_cooldown_list, ) - verbose_router_logger.info( - f"get_available_deployment for model: {model}, Selected deployment: {self.print_deployment(deployment)} for model: {model}" - ) + if verbose_router_logger.isEnabledFor(logging.INFO): + verbose_router_logger.info( + "get_available_deployment for model: %s, Selected deployment: %s for model: %s", + model, + self.print_deployment(deployment), + model, + ) return deployment def get_available_deployment_for_pass_through( @@ -9431,9 +9448,12 @@ class Router: cooldown_list=_cooldown_list, ) - verbose_router_logger.info( - f"get_available_deployment_for_pass_through model: {model}, selected deployment: {self.print_deployment(deployment)}" - ) + if verbose_router_logger.isEnabledFor(logging.INFO): + verbose_router_logger.info( + "get_available_deployment_for_pass_through model: %s, selected deployment: %s", + model, + self.print_deployment(deployment), + ) return deployment def _filter_cooldown_deployments( diff --git a/litellm/router_strategy/simple_shuffle.py b/litellm/router_strategy/simple_shuffle.py index ca82ddc6aa1..6da6544666f 100644 --- a/litellm/router_strategy/simple_shuffle.py +++ b/litellm/router_strategy/simple_shuffle.py @@ -5,6 +5,7 @@ If weights are provided, it will return a deployment based on the weights. """ +import logging import random from typing import TYPE_CHECKING, Any, Dict, List, Union @@ -52,9 +53,13 @@ def simple_shuffle( selected_index = random.choices(range(len(weights)), weights=weights)[0] verbose_router_logger.debug(f"\n selected index, {selected_index}") deployment = healthy_deployments[selected_index] - verbose_router_logger.info( - f"get_available_deployment for model: {model}, Selected deployment: {llm_router_instance.print_deployment(deployment) or deployment[0]} for model: {model}" - ) + if verbose_router_logger.isEnabledFor(logging.INFO): + verbose_router_logger.info( + "get_available_deployment for model: %s, Selected deployment: %s for model: %s", + model, + llm_router_instance.print_deployment(deployment) or deployment[0], + model, + ) return deployment or deployment[0] diff --git a/litellm/types/integrations/prometheus.py b/litellm/types/integrations/prometheus.py index 0856d8a6f9b..ead8cde00ea 100644 --- a/litellm/types/integrations/prometheus.py +++ b/litellm/types/integrations/prometheus.py @@ -3,7 +3,7 @@ from dataclasses import dataclass from enum import Enum from typing import Any, Dict, List, Literal, Optional, Tuple -from pydantic import BaseModel, Field, field_validator +from pydantic import BaseModel, Field, PrivateAttr, field_validator from typing_extensions import Annotated import litellm @@ -722,6 +722,8 @@ class UserAPIKeyLabelValues(BaseModel): Optional[str], Field(..., alias=UserAPIKeyLabelNames.STREAM.value) ] = None + _cached_dump: Optional[Dict[str, Any]] = PrivateAttr(default=None) + @field_validator("stream", mode="before") @classmethod def coerce_stream_to_str(cls, v: Any) -> Optional[str]: @@ -729,6 +731,12 @@ class UserAPIKeyLabelValues(BaseModel): return None return str(v) + def get_label_dict(self) -> Dict[str, Any]: + """Return cached model_dump() dict to avoid re-serializing on every prometheus_label_factory call.""" + if self._cached_dump is None: + self._cached_dump = self.model_dump() + return self._cached_dump + class PrometheusMetricsConfig(BaseModel): """Configuration for filtering Prometheus metrics""" diff --git a/tests/load_tests/compare_perf_results.py b/tests/load_tests/compare_perf_results.py new file mode 100644 index 00000000000..09e12d796e3 --- /dev/null +++ b/tests/load_tests/compare_perf_results.py @@ -0,0 +1,135 @@ +"""Compare baseline vs optimized locust load test results.""" +import csv +import sys +import os + + +def parse_stats_csv(filepath): + """Parse a locust stats CSV file.""" + if not os.path.exists(filepath): + return None + + with open(filepath) as f: + reader = csv.DictReader(f) + for row in reader: + if row.get("Name") == "Aggregated": + return { + "requests": int(row.get("Request Count", 0)), + "failures": int(row.get("Failure Count", 0)), + "median": float(row.get("Median Response Time", 0)), + "avg": float(row.get("Average Response Time", 0)), + "min": float(row.get("Min Response Time", 0)), + "max": float(row.get("Max Response Time", 0)), + "p50": float(row.get("50%", 0)), + "p66": float(row.get("66%", 0)), + "p75": float(row.get("75%", 0)), + "p80": float(row.get("80%", 0)), + "p90": float(row.get("90%", 0)), + "p95": float(row.get("95%", 0)), + "p98": float(row.get("98%", 0)), + "p99": float(row.get("99%", 0)), + "p999": float(row.get("99.9%", 0)), + "p9999": float(row.get("99.99%", 0)), + "rps": float(row.get("Requests/s", 0)), + } + return None + + +def print_comparison(label, baseline, optimized): + print() + print(f" {label}") + print("=" * 74) + print(f"{'Metric':<25} {'Baseline':>12} {'Optimized':>12} {'Change':>12} {'':>2}") + print("=" * 74) + + metrics = [ + ("Total Requests", "requests", "", False), + ("Failures", "failures", "", False), + ("Failure %", None, "%", False), + ("Requests/sec", "rps", " rps", True), + ("Median (ms)", "median", " ms", False), + ("Average (ms)", "avg", " ms", False), + ("P50 (ms)", "p50", " ms", False), + ("P75 (ms)", "p75", " ms", False), + ("P90 (ms)", "p90", " ms", False), + ("P95 (ms)", "p95", " ms", False), + ("P98 (ms)", "p98", " ms", False), + ("P99 (ms)", "p99", " ms", False), + ("P99.9 (ms)", "p999", " ms", False), + ("Max (ms)", "max", " ms", False), + ] + + for label_m, key, unit, higher_is_better in metrics: + if key is None: + b_val = (baseline["failures"] / baseline["requests"] * 100) if baseline["requests"] else 0 + o_val = (optimized["failures"] / optimized["requests"] * 100) if optimized["requests"] else 0 + else: + b_val = baseline[key] + o_val = optimized[key] + + if b_val > 0: + change = ((o_val - b_val) / b_val) * 100 + change_str = f"{change:+.1f}%" + if higher_is_better: + indicator = "+" if change > 2 else ("~" if change > -2 else "-") + else: + if key in ("requests", "failures", None): + indicator = "" + else: + indicator = "+" if change < -2 else ("~" if change < 2 else "-") + elif o_val == 0 and b_val == 0: + change_str = "0.0%" + indicator = "~" + else: + change_str = "N/A" + indicator = "" + print( + f"{label_m:<25} {b_val:>10.1f}{unit:>2} {o_val:>10.1f}{unit:>2} {change_str:>10} {indicator}" + ) + + print("=" * 74) + + +def main(): + results_dir = sys.argv[1] if len(sys.argv) > 1 else "tests/load_tests/results" + + # 5000 user comparison + baseline_5k = parse_stats_csv(os.path.join(results_dir, "baseline_stats.csv")) + optimized_5k = parse_stats_csv(os.path.join(results_dir, "optimized_stats.csv")) + + # 2000 user comparison + baseline_2k = parse_stats_csv(os.path.join(results_dir, "baseline_2k_stats.csv")) + optimized_2k = parse_stats_csv(os.path.join(results_dir, "optimized_2k_stats.csv")) + + print() + print("=" * 74) + print(" LOCUST BENCHMARK: BASELINE vs OPTIMIZED (GIL perf fixes)") + print(" 60s run time per test, warmed up proxy, mock LLM backend") + + if baseline_5k and optimized_5k: + print_comparison("5,000 CONCURRENT USERS (saturation test)", baseline_5k, optimized_5k) + + if baseline_2k and optimized_2k: + print_comparison("2,000 CONCURRENT USERS (sub-saturation test)", baseline_2k, optimized_2k) + + if baseline_5k and optimized_5k: + rps_5k = ((optimized_5k["rps"] - baseline_5k["rps"]) / baseline_5k["rps"]) * 100 + p50_5k = ((optimized_5k["p50"] - baseline_5k["p50"]) / baseline_5k["p50"]) * 100 if baseline_5k["p50"] else 0 + + print() + print("SUMMARY") + print("-" * 74) + print(f" 5k users: RPS {rps_5k:+.1f}% | P50 {p50_5k:+.1f}%") + + if baseline_2k and optimized_2k: + rps_2k = ((optimized_2k["rps"] - baseline_2k["rps"]) / baseline_2k["rps"]) * 100 + p50_2k = ((optimized_2k["p50"] - baseline_2k["p50"]) / baseline_2k["p50"]) * 100 if baseline_2k["p50"] else 0 + p98_2k = ((optimized_2k["p98"] - baseline_2k["p98"]) / baseline_2k["p98"]) * 100 if baseline_2k["p98"] else 0 + print(f" 2k users: RPS {rps_2k:+.1f}% | P50 {p50_2k:+.1f}% | P98 {p98_2k:+.1f}%") + + print() + return 0 + + +if __name__ == "__main__": + sys.exit(main() or 0) diff --git a/tests/load_tests/loadtest_config_perf.yaml b/tests/load_tests/loadtest_config_perf.yaml new file mode 100644 index 00000000000..bf7878a5f26 --- /dev/null +++ b/tests/load_tests/loadtest_config_perf.yaml @@ -0,0 +1,17 @@ +model_list: + - model_name: fake-openai-endpoint + litellm_params: + model: openai/fake-model + api_key: fake-key + api_base: http://127.0.0.1:18888/ + +general_settings: + master_key: sk-1234 + disable_spend_logs: False + +litellm_settings: + drop_params: True + telemetry: False + num_retries: 0 + request_timeout: 30 + callbacks: [] diff --git a/tests/load_tests/locustfile_perf.py b/tests/load_tests/locustfile_perf.py new file mode 100644 index 00000000000..6497bdde590 --- /dev/null +++ b/tests/load_tests/locustfile_perf.py @@ -0,0 +1,23 @@ +""" +Locust load test for performance comparison. +Uses a custom shape: 10s ramp to 5000 users, hold for 60s, then stop. +Results from the steady-state period are what matters. +""" +from locust import HttpUser, task, between + + +class ChatCompletionUser(HttpUser): + wait_time = between(0.01, 0.02) + + @task + def post_chat_completions(self): + headers = { + "Content-Type": "application/json", + "Authorization": "Bearer sk-1234", + } + data = { + "model": "fake-openai-endpoint", + "max_tokens": 10, + "messages": [{"role": "user", "content": "Hello"}], + } + self.client.post("/chat/completions", json=data, headers=headers) diff --git a/tests/load_tests/run_perf_comparison.sh b/tests/load_tests/run_perf_comparison.sh new file mode 100755 index 00000000000..a97150604db --- /dev/null +++ b/tests/load_tests/run_perf_comparison.sh @@ -0,0 +1,138 @@ +#!/bin/bash +set -e + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +WORKSPACE="$(cd "$SCRIPT_DIR/../.." && pwd)" +RESULTS_DIR="$SCRIPT_DIR/results" +mkdir -p "$RESULTS_DIR" + +USERS=${1:-5000} +SPAWN_RATE=${2:-500} +DURATION=${3:-60s} + +echo "================================================================" +echo " LiteLLM Performance Comparison: Baseline vs Optimized" +echo " Users: $USERS | Spawn Rate: $SPAWN_RATE | Duration: $DURATION" +echo "================================================================" + +wait_for_service() { + local url=$1 + local name=$2 + local max_attempts=${3:-60} + echo " Waiting for $name at $url..." + for i in $(seq 1 $max_attempts); do + if curl -s "$url" > /dev/null 2>&1; then + echo " $name is ready!" + return 0 + fi + sleep 1 + done + echo " ERROR: $name failed to start after $max_attempts seconds" + return 1 +} + +kill_port() { + local port=$1 + local pids=$(lsof -ti:$port 2>/dev/null || true) + if [ -n "$pids" ]; then + echo "$pids" | xargs kill -9 2>/dev/null || true + sleep 1 + fi +} + +# Start mock server +if ! curl -s http://127.0.0.1:18888/health > /dev/null 2>&1; then + echo "" + echo "Starting mock OpenAI server on port 18888..." + cd "$WORKSPACE" && poetry run python tests/load_tests/mock_openai_server.py & + MOCK_PID=$! + wait_for_service "http://127.0.0.1:18888/health" "Mock Server" 15 +else + echo "Mock server already running on port 18888" +fi + +# ---- PHASE 1: BASELINE (stash current changes) ---- +echo "" +echo "================================================================" +echo " PHASE 1: BASELINE (pre-optimization code)" +echo "================================================================" + +cd "$WORKSPACE" +CURRENT_COMMIT=$(git rev-parse HEAD) +PARENT_COMMIT=$(git rev-parse HEAD~1) + +echo " Current commit (optimized): ${CURRENT_COMMIT:0:12}" +echo " Parent commit (baseline): ${PARENT_COMMIT:0:12}" +echo " Checking out baseline..." +git checkout "$PARENT_COMMIT" -- \ + litellm/integrations/prometheus.py \ + litellm/litellm_core_utils/litellm_logging.py \ + litellm/litellm_core_utils/llm_cost_calc/tool_call_cost_tracking.py \ + litellm/litellm_core_utils/safe_json_dumps.py \ + litellm/proxy/litellm_pre_call_utils.py \ + litellm/proxy/spend_tracking/spend_tracking_utils.py \ + litellm/router.py \ + litellm/router_strategy/simple_shuffle.py \ + litellm/types/integrations/prometheus.py \ + 2>/dev/null + +kill_port 4000 + +echo " Starting proxy on port 4000 (baseline)..." +cd "$WORKSPACE" && poetry run litellm --config tests/load_tests/loadtest_config_perf.yaml --port 4000 > "$RESULTS_DIR/baseline_proxy.log" 2>&1 & +PROXY_PID=$! +wait_for_service "http://localhost:4000/health/liveliness" "LiteLLM Proxy (baseline)" 60 + +echo " Running baseline locust test..." +cd "$WORKSPACE" && poetry run locust -f tests/load_tests/locustfile_perf.py \ + --headless -u "$USERS" -r "$SPAWN_RATE" --run-time "$DURATION" \ + --host http://localhost:4000 \ + --csv "$RESULTS_DIR/baseline" \ + --only-summary 2>&1 | tee "$RESULTS_DIR/baseline_output.txt" + +kill $PROXY_PID 2>/dev/null || true +sleep 2 +kill_port 4000 + +# ---- PHASE 2: OPTIMIZED (restore current changes) ---- +echo "" +echo "================================================================" +echo " PHASE 2: OPTIMIZED (with performance fixes)" +echo "================================================================" + +cd "$WORKSPACE" +echo " Restoring optimized code..." +git checkout "$CURRENT_COMMIT" -- \ + litellm/integrations/prometheus.py \ + litellm/litellm_core_utils/litellm_logging.py \ + litellm/litellm_core_utils/llm_cost_calc/tool_call_cost_tracking.py \ + litellm/litellm_core_utils/safe_json_dumps.py \ + litellm/proxy/litellm_pre_call_utils.py \ + litellm/proxy/spend_tracking/spend_tracking_utils.py \ + litellm/router.py \ + litellm/router_strategy/simple_shuffle.py \ + litellm/types/integrations/prometheus.py \ + 2>/dev/null + +kill_port 4000 + +echo " Starting proxy on port 4000 (optimized)..." +cd "$WORKSPACE" && poetry run litellm --config tests/load_tests/loadtest_config_perf.yaml --port 4000 > "$RESULTS_DIR/optimized_proxy.log" 2>&1 & +PROXY_PID=$! +wait_for_service "http://localhost:4000/health/liveliness" "LiteLLM Proxy (optimized)" 60 + +echo " Running optimized locust test..." +cd "$WORKSPACE" && poetry run locust -f tests/load_tests/locustfile_perf.py \ + --headless -u "$USERS" -r "$SPAWN_RATE" --run-time "$DURATION" \ + --host http://localhost:4000 \ + --csv "$RESULTS_DIR/optimized" \ + --only-summary 2>&1 | tee "$RESULTS_DIR/optimized_output.txt" + +kill $PROXY_PID 2>/dev/null || true + +# ---- PHASE 3: COMPARE ---- +echo "" +echo "================================================================" +echo " RESULTS COMPARISON" +echo "================================================================" +cd "$WORKSPACE" && poetry run python tests/load_tests/compare_perf_results.py "$RESULTS_DIR"