[Feature] Add request_duration_ms to SpendLogs

Add a `request_duration_ms` column to `LiteLLM_SpendLogs` to track request
duration. New rows are computed at write time. Legacy rows use a COALESCE
fallback in the `/spend/logs/ui` query to compute duration on the fly from
`endTime - startTime`. The field is also sortable in the UI endpoint.

Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>

litellm-proxy-extras/litellm_proxy_extras/migrations/20260224201417_spend_logs_request_duration/migration.sql

@@ -0,0 +1,2 @@
+-- AlterTable
+ALTER TABLE "LiteLLM_SpendLogs" ADD COLUMN     "request_duration_ms" INTEGER;

litellm-proxy-extras/litellm_proxy_extras/schema.prisma

@@ -477,6 +477,7 @@ model LiteLLM_SpendLogs {
   completion_tokens   Int     @default(0)
   startTime           DateTime // Assuming start_time is a DateTime field
   endTime             DateTime // Assuming end_time is a DateTime field
+  request_duration_ms Int?
   completionStartTime DateTime? // Assuming completionStartTime is a DateTime field
   model               String   @default("")
   model_id            String?   @default("") // the model id stored in proxy model db

litellm/proxy/_types.py

@@ -3105,6 +3105,7 @@ class SpendLogsPayload(TypedDict):
     response: Optional[Union[str, list, dict]]
     proxy_server_request: Optional[str]
     session_id: Optional[str]
+    request_duration_ms: Optional[int]
     status: Literal["success", "failure"]
 
 

litellm/proxy/schema.prisma

@@ -477,6 +477,7 @@ model LiteLLM_SpendLogs {
   completion_tokens   Int     @default(0)
   startTime           DateTime // Assuming start_time is a DateTime field
   endTime             DateTime // Assuming end_time is a DateTime field
+  request_duration_ms Int?
   completionStartTime DateTime? // Assuming completionStartTime is a DateTime field
   model               String   @default("")
   model_id            String?   @default("") // the model id stored in proxy model db

litellm/proxy/spend_tracking/spend_management_endpoints.py

@@ -1726,7 +1726,7 @@ async def ui_view_spend_logs(  # noqa: PLR0915
         )
 
     # Validate sort_by and sort_order
-    valid_sort_fields = {"spend", "total_tokens", "startTime", "endTime"}
+    valid_sort_fields = {"spend", "total_tokens", "startTime", "endTime", "request_duration_ms"}
     if sort_by not in valid_sort_fields:
         raise ProxyException(
             message=f"Invalid sort_by: {sort_by}. Must be one of: {', '.join(sorted(valid_sort_fields))}",
@@ -1939,7 +1939,8 @@ async def ui_view_spend_logs(  # noqa: PLR0915
                 custom_llm_provider, api_base, "user", metadata,
                 cache_hit, cache_key, request_tags, team_id,
                 organization_id, end_user, requester_ip_address,
-                session_id, status, mcp_namespaced_tool_name, agent_id
+                session_id, status, mcp_namespaced_tool_name, agent_id,
+                COALESCE(request_duration_ms, (EXTRACT(EPOCH FROM ("endTime" - "startTime")) * 1000)::INTEGER) AS request_duration_ms
             FROM "LiteLLM_SpendLogs"
             WHERE {" AND ".join(sql_conditions)}
             ORDER BY {_sql_col} {_sql_dir}

litellm/proxy/spend_tracking/spend_tracking_utils.py

@@ -447,6 +447,7 @@ def get_logging_payload(  # noqa: PLR0915
                 kwargs=kwargs,
                 standard_logging_payload=standard_logging_payload,
             ),
+            request_duration_ms=_get_request_duration_ms(start_time, end_time),
             status=_get_status_for_spend_log(
                 metadata=metadata,
             ),
@@ -496,6 +497,16 @@ def _get_session_id_for_spend_log(
     return str(uuid.uuid4())
 
 
+def _get_request_duration_ms(
+    start_time: datetime, end_time: datetime
+) -> Optional[int]:
+    """Compute request duration in milliseconds from start and end times."""
+    try:
+        return int((end_time - start_time).total_seconds() * 1000)
+    except Exception:
+        return None
+
+
 def _ensure_datetime_utc(timestamp: datetime) -> datetime:
     """Helper to ensure datetime is in UTC"""
     timestamp = timestamp.astimezone(timezone.utc)

schema.prisma

@@ -477,6 +477,7 @@ model LiteLLM_SpendLogs {
   completion_tokens   Int     @default(0)
   startTime           DateTime // Assuming start_time is a DateTime field
   endTime             DateTime // Assuming end_time is a DateTime field
+  request_duration_ms Int?
   completionStartTime DateTime? // Assuming completionStartTime is a DateTime field
   model               String   @default("")
   model_id            String?   @default("") // the model id stored in proxy model db

tests/test_litellm/proxy/spend_tracking/test_spend_management_endpoints.py

@@ -274,6 +274,7 @@ ignored_keys = [
     "endTime",
     "completionStartTime",
     "endTime",
+    "request_duration_ms",
     "organization_id",
     "metadata.model_map_information",
     "metadata.usage_object",
@@ -606,6 +607,82 @@ async def test_ui_view_spend_logs_sort_validation_errors(
         app.dependency_overrides.pop(ps.user_api_key_auth, None)
 
 
+@pytest.mark.asyncio
+async def test_ui_view_spend_logs_sort_by_request_duration_ms(client, monkeypatch):
+    """Test that request_duration_ms is accepted as a valid sort_by field."""
+    base_logs = [
+        {
+            "request_id": "req_fast",
+            "api_key": "sk-test-key",
+            "user": "user1",
+            "spend": 0.10,
+            "total_tokens": 100,
+            "request_duration_ms": 100,
+            "startTime": "2025-01-01T00:00:00+00:00",
+            "endTime": "2025-01-01T00:00:00.100000+00:00",
+            "model": "gpt-4",
+        },
+        {
+            "request_id": "req_slow",
+            "api_key": "sk-test-key",
+            "user": "user1",
+            "spend": 0.05,
+            "total_tokens": 50,
+            "request_duration_ms": 5000,
+            "startTime": "2025-01-01T00:00:01+00:00",
+            "endTime": "2025-01-01T00:00:06+00:00",
+            "model": "gpt-4",
+        },
+    ]
+
+    async def mock_count(*args, **kwargs):
+        return len(base_logs)
+
+    async def mock_query_raw(sql_query, *params):
+        reverse = "DESC" in sql_query
+        sorted_logs = sorted(
+            base_logs, key=lambda x: x.get("request_duration_ms", 0), reverse=reverse
+        )
+        page_size = params[-2] if len(params) >= 2 else 50
+        skip = params[-1] if len(params) >= 1 else 0
+        return sorted_logs[skip : skip + page_size]
+
+    class MockPrismaClient:
+        def __init__(self):
+            self.db = MagicMock()
+            self.db.litellm_spendlogs = MagicMock()
+            self.db.litellm_spendlogs.count = AsyncMock(side_effect=mock_count)
+            self.db.query_raw = AsyncMock(side_effect=mock_query_raw)
+
+    monkeypatch.setattr("litellm.proxy.proxy_server.prisma_client", MockPrismaClient())
+    monkeypatch.setattr(
+        "litellm.proxy.spend_tracking.spend_management_endpoints._is_admin_view_safe",
+        lambda user_api_key_dict: True,
+    )
+    app.dependency_overrides[ps.user_api_key_auth] = lambda: UserAPIKeyAuth(
+        user_role=LitellmUserRoles.PROXY_ADMIN, user_id="admin_user"
+    )
+
+    try:
+        response = client.get(
+            "/spend/logs/ui",
+            params={
+                "start_date": "2024-12-25 00:00:00",
+                "end_date": "2025-01-02 23:59:59",
+                "sort_by": "request_duration_ms",
+                "sort_order": "asc",
+            },
+            headers={"Authorization": "Bearer sk-test"},
+        )
+
+        assert response.status_code == 200, response.text
+        data = response.json()
+        actual_ids = [log["request_id"] for log in data["data"]]
+        assert actual_ids == ["req_fast", "req_slow"]
+    finally:
+        app.dependency_overrides.pop(ps.user_api_key_auth, None)
+
+
 @pytest.mark.asyncio
 async def test_ui_view_spend_logs_with_team_id(client, monkeypatch):
     mock_spend_logs = [

tests/test_litellm/proxy/spend_tracking/test_spend_tracking_utils.py

@@ -20,6 +20,7 @@ from litellm.constants import LITELLM_TRUNCATED_PAYLOAD_FIELD, REDACTED_BY_LITEL
 from litellm.litellm_core_utils.safe_json_dumps import safe_dumps
 from litellm.proxy.spend_tracking.spend_tracking_utils import (
     _get_proxy_server_request_for_spend_logs_payload,
+    _get_request_duration_ms,
     _get_response_for_spend_logs_payload,
     _get_spend_logs_metadata,
     _get_vector_store_request_for_spend_logs_payload,
@@ -1232,3 +1233,50 @@ def test_get_logging_payload_handles_missing_retry_info_gracefully():
         metadata.get("max_retries") is None
     ), "max_retries should be None when not provided"
 
+
+def test_get_request_duration_ms_normal():
+    """Test that request duration is correctly computed in milliseconds."""
+    start = datetime.datetime(2025, 1, 1, 0, 0, 0, tzinfo=timezone.utc)
+    end = datetime.datetime(2025, 1, 1, 0, 0, 2, 500000, tzinfo=timezone.utc)  # 2.5s later
+    result = _get_request_duration_ms(start, end)
+    assert result == 2500
+
+
+def test_get_request_duration_ms_sub_millisecond():
+    """Test that sub-millisecond durations are truncated to int."""
+    start = datetime.datetime(2025, 1, 1, 0, 0, 0, 0, tzinfo=timezone.utc)
+    end = datetime.datetime(2025, 1, 1, 0, 0, 0, 500, tzinfo=timezone.utc)  # 0.5ms
+    result = _get_request_duration_ms(start, end)
+    assert result == 0
+
+
+def test_get_request_duration_ms_zero():
+    """Test that identical start and end times produce 0."""
+    t = datetime.datetime(2025, 1, 1, 0, 0, 0, tzinfo=timezone.utc)
+    result = _get_request_duration_ms(t, t)
+    assert result == 0
+
+
+def test_get_logging_payload_includes_request_duration_ms():
+    """Test that get_logging_payload populates request_duration_ms."""
+    start_time = datetime.datetime(2025, 1, 1, 0, 0, 0, tzinfo=timezone.utc)
+    end_time = datetime.datetime(2025, 1, 1, 0, 0, 3, tzinfo=timezone.utc)  # 3s later
+
+    kwargs = {
+        "model": "gpt-4",
+        "litellm_params": {"api_base": "https://api.openai.com"},
+        "standard_logging_object": None,
+    }
+    response_obj = {"usage": {"prompt_tokens": 10, "completion_tokens": 5, "total_tokens": 15}}
+
+    with patch("litellm.proxy.proxy_server.master_key", None), \
+         patch("litellm.proxy.proxy_server.general_settings", {}):
+        payload = get_logging_payload(
+            kwargs=kwargs,
+            response_obj=response_obj,
+            start_time=start_time,
+            end_time=end_time,
+        )
+
+    assert payload["request_duration_ms"] == 3000
+