feat(prometheus): add new latency metrics for upstream, gateway, and streaming chunks

This update introduces several new Prometheus metrics to track latency:
- `litellm_upstream_latency_seconds`: Measures total latency for upstream LLM provider calls.
- `litellm_gateway_latency_seconds`: Captures total latency for requests through the LiteLLM gateway.
- `litellm_gateway_overhead_seconds`: Computes overhead latency as the difference between gateway and upstream latencies.
- `litellm_stream_first_chunk_overhead_latency_metric`: Records processing latency for the first streamed chunk.
- `litellm_stream_chunk_overhead_latency_metric`: Measures processing latency for subsequent streamed chunks.

Additionally, the logging structure has been updated to include the new metrics, ensuring they are recorded accurately during API calls. This enhancement aims to improve observability and performance analysis of the LiteLLM system.
This commit is contained in:
harish-berri 2026-05-09 23:10:14 +00:00
parent 0bcff0214a
commit 8b9946c9aa
7 changed files with 371 additions and 28 deletions

View file

@ -124,6 +124,33 @@ class PrometheusLogger(CustomLogger):
buckets=self.latency_buckets,
)
self.litellm_upstream_latency_seconds = self._histogram_factory(
"litellm_upstream_latency_seconds",
"Total latency (seconds) spent in upstream LLM provider calls",
labelnames=self.get_labels_for_metric(
"litellm_upstream_latency_seconds"
),
buckets=self.latency_buckets,
)
self.litellm_gateway_latency_seconds = self._histogram_factory(
"litellm_gateway_latency_seconds",
"Total latency (seconds) for a request through the LiteLLM gateway",
labelnames=self.get_labels_for_metric(
"litellm_gateway_latency_seconds"
),
buckets=self.latency_buckets,
)
self.litellm_gateway_overhead_seconds = self._histogram_factory(
"litellm_gateway_overhead_seconds",
"LiteLLM gateway overhead latency (seconds), computed as gateway latency minus upstream LLM latency",
labelnames=self.get_labels_for_metric(
"litellm_gateway_overhead_seconds"
),
buckets=self.latency_buckets,
)
self.litellm_llm_api_time_to_first_token_metric = self._histogram_factory(
"litellm_llm_api_time_to_first_token_metric",
"Time to first token for a models LLM API call",
@ -140,6 +167,24 @@ class PrometheusLogger(CustomLogger):
buckets=self.latency_buckets,
)
self.litellm_stream_first_chunk_overhead_latency_metric = self._histogram_factory(
"litellm_stream_first_chunk_overhead_latency_metric",
"LiteLLM proxy processing latency (seconds) for the first streamed chunk before yielding to the client",
labelnames=self.get_labels_for_metric(
"litellm_stream_first_chunk_overhead_latency_metric"
),
buckets=self.latency_buckets,
)
self.litellm_stream_chunk_overhead_latency_metric = self._histogram_factory(
"litellm_stream_chunk_overhead_latency_metric",
"LiteLLM proxy processing latency (seconds) for streamed chunks after the first chunk before yielding to the client",
labelnames=self.get_labels_for_metric(
"litellm_stream_chunk_overhead_latency_metric"
),
buckets=self.latency_buckets,
)
# Counter for spend
self.litellm_spend_metric = self._counter_factory(
"litellm_spend_metric",
@ -1499,7 +1544,27 @@ class PrometheusLogger(CustomLogger):
end_time: datetime = kwargs.get("end_time") or datetime.now()
start_time: Optional[datetime] = kwargs.get("start_time")
api_call_start_time = kwargs.get("api_call_start_time", None)
api_call_end_time = kwargs.get("api_call_end_time", None)
completion_start_time = kwargs.get("completion_start_time", None)
standard_logging_payload = kwargs.get("standard_logging_object") or {}
standard_logging_hidden_params = (
standard_logging_payload.get("hidden_params", {})
if isinstance(standard_logging_payload, dict)
else {}
)
llm_api_duration_ms = kwargs.get(
"llm_api_duration_ms",
standard_logging_hidden_params.get("llm_api_duration_ms"),
)
upstream_duration_seconds = self._safe_duration_seconds(
start_time=api_call_start_time,
end_time=api_call_end_time,
)
if isinstance(llm_api_duration_ms, (int, float)) and llm_api_duration_ms >= 0:
upstream_duration_seconds = upstream_duration_seconds or (
llm_api_duration_ms / 1000
)
time_to_first_token_seconds = self._safe_duration_seconds(
start_time=api_call_start_time,
end_time=completion_start_time,
@ -1549,6 +1614,23 @@ class PrometheusLogger(CustomLogger):
_labels,
)
if upstream_duration_seconds is not None:
_upstream_labels = prometheus_label_factory(
supported_enum_labels=self.get_labels_for_metric(
metric_name="litellm_upstream_latency_seconds"
),
enum_values=enum_values,
label_context=label_context,
)
self.litellm_upstream_latency_seconds.labels(**_upstream_labels).observe(
upstream_duration_seconds
)
self._track_end_user_metric_series(
self.litellm_upstream_latency_seconds,
"litellm_upstream_latency_seconds",
_upstream_labels,
)
# total request latency
total_time_seconds = self._safe_duration_seconds(
start_time=start_time,
@ -1571,6 +1653,58 @@ class PrometheusLogger(CustomLogger):
_labels,
)
# Gateway/upstream/overhead metrics must use the same
# sample set. Cache hits and other successes without a provider call
# still belong in litellm_request_total_latency_metric above, but they
# cannot be compared against upstream latency.
if total_time_seconds is not None and upstream_duration_seconds is not None:
_gateway_labels = prometheus_label_factory(
supported_enum_labels=self.get_labels_for_metric(
metric_name="litellm_gateway_latency_seconds"
),
enum_values=enum_values,
label_context=label_context,
)
self.litellm_gateway_latency_seconds.labels(**_gateway_labels).observe(
total_time_seconds
)
self._track_end_user_metric_series(
self.litellm_gateway_latency_seconds,
"litellm_gateway_latency_seconds",
_gateway_labels,
)
overhead_seconds = max(total_time_seconds - upstream_duration_seconds, 0)
_labels = prometheus_label_factory(
supported_enum_labels=self.get_labels_for_metric(
metric_name="litellm_overhead_latency_metric"
),
enum_values=enum_values,
label_context=label_context,
)
self.litellm_overhead_latency_metric.labels(**_labels).observe(
overhead_seconds
)
self._track_end_user_metric_series(
self.litellm_overhead_latency_metric,
"litellm_overhead_latency_metric",
_labels,
)
_gateway_overhead_labels = prometheus_label_factory(
supported_enum_labels=self.get_labels_for_metric(
metric_name="litellm_gateway_overhead_seconds"
),
enum_values=enum_values,
label_context=label_context,
)
self.litellm_gateway_overhead_seconds.labels(
**_gateway_overhead_labels
).observe(overhead_seconds)
self._track_end_user_metric_series(
self.litellm_gateway_overhead_seconds,
"litellm_gateway_overhead_seconds",
_gateway_overhead_labels,
)
# request queue time (time from arrival to processing start)
_litellm_params = kwargs.get("litellm_params", {}) or {}
queue_time_seconds = (_litellm_params.get("metadata") or {}).get(
@ -1593,6 +1727,75 @@ class PrometheusLogger(CustomLogger):
_labels,
)
def record_streaming_chunk_overhead(
self,
*,
user_api_key_dict: Any,
request_data: dict,
duration_seconds: float,
is_first_chunk: bool,
) -> None:
metric_name: DEFINED_PROMETHEUS_METRICS = (
"litellm_stream_first_chunk_overhead_latency_metric"
if is_first_chunk
else "litellm_stream_chunk_overhead_latency_metric"
)
metric = (
self.litellm_stream_first_chunk_overhead_latency_metric
if is_first_chunk
else self.litellm_stream_chunk_overhead_latency_metric
)
metadata = request_data.get("metadata") or {}
if not isinstance(metadata, dict):
metadata = {}
litellm_metadata = request_data.get("litellm_metadata") or {}
if not isinstance(litellm_metadata, dict):
litellm_metadata = {}
model_info = (
litellm_metadata.get("model_info") or metadata.get("model_info") or {}
)
if not isinstance(model_info, dict):
model_info = {}
enum_values = UserAPIKeyLabelValues(
end_user=metadata.get("user_api_key_end_user_id"),
hashed_api_key=getattr(user_api_key_dict, "api_key", None)
or metadata.get("user_api_key_hash"),
api_key_alias=getattr(user_api_key_dict, "key_alias", None)
or metadata.get("user_api_key_alias"),
requested_model=request_data.get("_litellm_client_requested_model")
or request_data.get("model"),
model=request_data.get("model"),
litellm_model_name=request_data.get("model"),
team=getattr(user_api_key_dict, "team_id", None)
or metadata.get("user_api_key_team_id"),
team_alias=getattr(user_api_key_dict, "team_alias", None)
or metadata.get("user_api_key_team_alias"),
org_id=getattr(user_api_key_dict, "organization_id", None)
or metadata.get("user_api_key_org_id"),
org_alias=getattr(user_api_key_dict, "organization_alias", None)
or metadata.get("user_api_key_org_alias"),
user=getattr(user_api_key_dict, "user_id", None)
or metadata.get("user_api_key_user_id"),
user_email=getattr(user_api_key_dict, "user_email", None)
or metadata.get("user_api_key_user_email"),
model_id=model_info.get("id") or metadata.get("model_id"),
route=getattr(user_api_key_dict, "request_route", None)
or metadata.get("user_api_key_request_route"),
client_ip=metadata.get("requester_ip_address"),
user_agent=metadata.get("user_agent"),
custom_metadata_labels=get_custom_labels_from_metadata(metadata=metadata),
stream="True" if litellm.prometheus_emit_stream_label else None,
)
label_context = PrometheusLabelFactoryContext(enum_values)
labels = prometheus_label_factory(
supported_enum_labels=self.get_labels_for_metric(metric_name=metric_name),
enum_values=enum_values,
label_context=label_context,
)
metric.labels(**labels).observe(duration_seconds)
self._track_end_user_metric_series(metric, metric_name, labels)
async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time):
verbose_logger.debug(
"prometheus Logging - Enters failure logging function (kwargs keys: %s)",
@ -2256,20 +2459,6 @@ class PrometheusLogger(CustomLogger):
"x_ratelimit_remaining_tokens", None
)
if litellm_overhead_time_ms := standard_logging_payload[
"hidden_params"
].get("litellm_overhead_time_ms"):
_labels = prometheus_label_factory(
supported_enum_labels=self.get_labels_for_metric(
metric_name="litellm_overhead_latency_metric"
),
enum_values=enum_values,
label_context=label_context,
)
self.litellm_overhead_latency_metric.labels(**_labels).observe(
litellm_overhead_time_ms / 1000
) # set as seconds
if remaining_requests:
"""
"model_group",
@ -3699,7 +3888,7 @@ def get_custom_labels_from_metadata(metadata: dict) -> Dict[str, str]:
def _get_combined_custom_metadata_from_standard_logging_payload(
standard_logging_payload: Optional[dict],
standard_logging_payload: Optional[Union[dict, StandardLoggingPayload]],
) -> Dict[str, Any]:
"""
Combine the metadata sources that can supply custom Prometheus labels.

View file

@ -1219,6 +1219,7 @@ class Logging(LiteLLMLoggingBaseClass):
self.model_call_details["original_response"] = original_response
self.model_call_details["additional_args"] = additional_args
self.model_call_details["log_event_type"] = "post_api_call"
self.model_call_details["api_call_end_time"] = datetime.datetime.now()
if self.litellm_request_debug:
attr = "warning"
@ -5041,6 +5042,7 @@ class StandardLoggingPayloadSetup:
response_cost=None,
additional_headers=None,
litellm_overhead_time_ms=None,
llm_api_duration_ms=None,
batch_models=None,
litellm_model_name=None,
usage_object=None,

View file

@ -104,6 +104,7 @@ class ResponseMetadata:
overhead_ms = round(total_response_time_ms - llm_api_duration_ms, 4)
self._update_hidden_params(
{
"llm_api_duration_ms": round(llm_api_duration_ms, 4),
"litellm_overhead_time_ms": overhead_ms,
}
)

View file

@ -15,11 +15,13 @@ import threading
import time
import traceback
import warnings
from collections import deque
from datetime import datetime, timedelta, timezone
from typing import (
TYPE_CHECKING,
Any,
AsyncGenerator,
Deque,
Dict,
List,
Literal,
@ -6484,6 +6486,57 @@ def _restamp_streaming_chunk_model(
return chunk, model_mismatch_logged
def _get_prometheus_logger_for_streaming_metrics() -> Optional[Any]:
for callback in litellm.callbacks:
if hasattr(callback, "record_streaming_chunk_overhead"):
return callback
return None
def _record_streaming_chunk_overhead(
*,
prometheus_logger: Optional[Any],
user_api_key_dict: UserAPIKeyAuth,
request_data: dict,
chunk_start_time: float,
is_first_chunk: bool,
) -> None:
if prometheus_logger is None:
return
try:
prometheus_logger.record_streaming_chunk_overhead(
user_api_key_dict=user_api_key_dict,
request_data=request_data,
duration_seconds=time.perf_counter() - chunk_start_time,
is_first_chunk=is_first_chunk,
)
except Exception as e:
verbose_proxy_logger.debug(
"Failed to record streaming chunk overhead metric: %s", e
)
async def _timestamp_streaming_chunks(
*, response: Any, chunk_start_times: Deque[float]
) -> AsyncGenerator[Any, None]:
async for chunk in response:
chunk_start_times.append(time.perf_counter())
yield chunk
def _get_timestamped_streaming_response(
response: Any,
) -> Tuple[AsyncGenerator[Any, None], Deque[float]]:
chunk_start_times: Deque[float] = deque()
return (
_timestamp_streaming_chunks(
response=response,
chunk_start_times=chunk_start_times,
),
chunk_start_times,
)
async def async_data_generator(
response, user_api_key_dict: UserAPIKeyAuth, request_data: dict
):
@ -6498,11 +6551,21 @@ async def async_data_generator(
# Previously "".join(str_so_far_parts) was called every chunk, re-joining
# the entire accumulated response. String += is O(n) amortized total.
_str_so_far: str = ""
prometheus_logger = _get_prometheus_logger_for_streaming_metrics()
is_first_streaming_chunk = True
timestamped_response, chunk_start_times = _get_timestamped_streaming_response(
response
)
async for chunk in proxy_logging_obj.async_post_call_streaming_iterator_hook(
user_api_key_dict=user_api_key_dict,
response=response,
response=timestamped_response,
request_data=request_data,
):
chunk_start_time = (
chunk_start_times.popleft()
if chunk_start_times
else time.perf_counter()
)
### CALL HOOKS ### - modify outgoing data
chunk = await proxy_logging_obj.async_post_call_streaming_hook(
user_api_key_dict=user_api_key_dict,
@ -6530,14 +6593,21 @@ async def async_data_generator(
try:
yield f"data: {chunk}\n\n"
_record_streaming_chunk_overhead(
prometheus_logger=prometheus_logger,
user_api_key_dict=user_api_key_dict,
request_data=request_data,
chunk_start_time=chunk_start_time,
is_first_chunk=is_first_streaming_chunk,
)
is_first_streaming_chunk = False
except Exception as e:
yield f"data: {str(e)}\n\n"
# Streaming is done, yield the [DONE] chunk
if error_message is not None:
yield error_message
done_message = "[DONE]"
yield f"data: {done_message}\n\n"
yield "data: [DONE]\n\n"
except Exception as e:
verbose_proxy_logger.exception(
"litellm.proxy.proxy_server.async_data_generator(): Exception occured - {}".format(

View file

@ -189,6 +189,11 @@ DEFINED_PROMETHEUS_METRICS = Literal[
"litellm_llm_api_latency_metric",
"litellm_llm_api_time_to_first_token_metric",
"litellm_request_total_latency_metric",
"litellm_upstream_latency_seconds",
"litellm_gateway_latency_seconds",
"litellm_gateway_overhead_seconds",
"litellm_stream_first_chunk_overhead_latency_metric",
"litellm_stream_chunk_overhead_latency_metric",
"litellm_overhead_latency_metric",
"litellm_remaining_requests_metric",
"litellm_remaining_tokens_metric",
@ -289,6 +294,10 @@ class PrometheusMetricLabels:
UserAPIKeyLabelNames.MODEL_ID.value,
]
litellm_upstream_latency_seconds = litellm_request_total_latency_metric
litellm_gateway_latency_seconds = litellm_request_total_latency_metric
litellm_gateway_overhead_seconds = litellm_request_total_latency_metric
litellm_request_queue_time_seconds = [
UserAPIKeyLabelNames.END_USER.value,
UserAPIKeyLabelNames.API_KEY_HASH.value,
@ -301,6 +310,23 @@ class PrometheusMetricLabels:
UserAPIKeyLabelNames.MODEL_ID.value,
]
_stream_chunk_overhead_labels = [
UserAPIKeyLabelNames.v1_LITELLM_MODEL_NAME.value,
UserAPIKeyLabelNames.API_KEY_HASH.value,
UserAPIKeyLabelNames.API_KEY_ALIAS.value,
UserAPIKeyLabelNames.REQUESTED_MODEL.value,
UserAPIKeyLabelNames.TEAM.value,
UserAPIKeyLabelNames.TEAM_ALIAS.value,
UserAPIKeyLabelNames.USER.value,
UserAPIKeyLabelNames.USER_EMAIL.value,
UserAPIKeyLabelNames.ROUTE.value,
UserAPIKeyLabelNames.CLIENT_IP.value,
UserAPIKeyLabelNames.USER_AGENT.value,
UserAPIKeyLabelNames.MODEL_ID.value,
]
litellm_stream_first_chunk_overhead_latency_metric = _stream_chunk_overhead_labels
litellm_stream_chunk_overhead_latency_metric = _stream_chunk_overhead_labels
# Guardrail metrics - these use custom labels (guardrail_name, status, error_type, hook_type)
# which are not part of UserAPIKeyLabelNames
litellm_guardrail_latency_seconds: List[str] = []
@ -351,15 +377,7 @@ class PrometheusMetricLabels:
UserAPIKeyLabelNames.TEAM_ALIAS.value,
]
litellm_overhead_latency_metric = [
UserAPIKeyLabelNames.MODEL_GROUP.value,
UserAPIKeyLabelNames.API_PROVIDER.value,
UserAPIKeyLabelNames.API_BASE.value,
UserAPIKeyLabelNames.v2_LITELLM_MODEL_NAME.value,
UserAPIKeyLabelNames.API_KEY_HASH.value,
UserAPIKeyLabelNames.API_KEY_ALIAS.value,
UserAPIKeyLabelNames.MODEL_ID.value,
]
litellm_overhead_latency_metric = litellm_request_total_latency_metric
litellm_remaining_requests_metric = [
UserAPIKeyLabelNames.MODEL_GROUP.value,
@ -652,6 +670,12 @@ class PrometheusMetricLabels:
"litellm_llm_api_latency_metric",
"litellm_llm_api_time_to_first_token_metric",
"litellm_request_total_latency_metric",
"litellm_upstream_latency_seconds",
"litellm_gateway_latency_seconds",
"litellm_gateway_overhead_seconds",
"litellm_overhead_latency_metric",
"litellm_stream_first_chunk_overhead_latency_metric",
"litellm_stream_chunk_overhead_latency_metric",
"litellm_request_queue_time_seconds",
"litellm_proxy_total_requests_metric",
"litellm_proxy_failed_requests_metric",

View file

@ -2662,6 +2662,7 @@ class StandardLoggingHiddenParams(TypedDict):
api_base: Optional[str]
response_cost: Optional[Union[str, float]]
litellm_overhead_time_ms: Optional[float]
llm_api_duration_ms: Optional[float]
additional_headers: Optional[StandardLoggingAdditionalHeaders]
batch_models: Optional[List[str]]
litellm_model_name: Optional[str] # the model name sent to the provider by litellm

View file

@ -81,6 +81,63 @@ def test_prometheus_metric_labels_have_remaining_metrics():
), "litellm_remaining_tokens_metric should have api_base label"
@pytest.mark.parametrize(
"metric_name",
[
"litellm_stream_first_chunk_overhead_latency_metric",
"litellm_stream_chunk_overhead_latency_metric",
],
)
def test_streaming_chunk_overhead_metrics_are_defined(metric_name):
from litellm.types.integrations.prometheus import (
DEFINED_PROMETHEUS_METRICS,
PrometheusMetricLabels,
)
defined_metrics = get_args(DEFINED_PROMETHEUS_METRICS)
assert metric_name in defined_metrics
labels = PrometheusMetricLabels.get_labels(metric_name)
assert "model" in labels
assert "hashed_api_key" in labels
assert "route" in labels
def test_overhead_latency_metric_uses_request_latency_labels():
from litellm.types.integrations.prometheus import PrometheusMetricLabels
overhead_labels = PrometheusMetricLabels.get_labels(
"litellm_overhead_latency_metric"
)
total_latency_labels = PrometheusMetricLabels.get_labels(
"litellm_request_total_latency_metric"
)
assert overhead_labels == total_latency_labels
@pytest.mark.parametrize(
"metric_name",
[
"litellm_upstream_latency_seconds",
"litellm_gateway_latency_seconds",
"litellm_gateway_overhead_seconds",
],
)
def test_bifrost_style_latency_metrics_are_defined(metric_name):
from litellm.types.integrations.prometheus import (
DEFINED_PROMETHEUS_METRICS,
PrometheusMetricLabels,
)
defined_metrics = get_args(DEFINED_PROMETHEUS_METRICS)
assert metric_name in defined_metrics
assert PrometheusMetricLabels.get_labels(
metric_name
) == PrometheusMetricLabels.get_labels("litellm_request_total_latency_metric")
def test_all_defined_metrics_have_consistent_naming():
"""
Test that all metrics defined in DEFINED_PROMETHEUS_METRICS follow
@ -104,4 +161,3 @@ if __name__ == "__main__":
test_remaining_tokens_metric_name_in_defined_metrics()
test_prometheus_metric_labels_have_remaining_metrics()
test_all_defined_metrics_have_consistent_naming()
print("All prometheus metric name consistency tests passed!")