fix(logging): do not stamp a provider handoff when pre_call runs for a proxy-only failure (#47456)

Co-authored-by: devin-ai-integration[bot] <158243242+devin-ai-integration[bot]@users.noreply.github.com>

litellm/litellm_core_utils/litellm_logging.py

@@ -44,6 +44,7 @@ from litellm.constants import (
     EMPTY_MAPPING,
     INTERNAL_CALLBACK_NAMES,
     KUBERNETES_POD_ROUTING_KEY,
+    LITELLM_LOGGING_NO_UPSTREAM_LLM_CALL,
     PROVIDER_REQUEST_ID_HEADERS,
     REDACTED_BY_LITELLM,
 )
@@ -1531,15 +1532,20 @@ class Logging(LiteLLMLoggingBaseClass):
                         "LiteLLM.LoggingError: [Non-Blocking] Exception occurred while logging %s", e
                     )
 
-            self.model_call_details["api_call_start_time"] = datetime.datetime.now()
-            # Set-once first provider-handoff instant. api_call_start_time
-            # is overwritten on every retry, so it can't measure one-time
-            # preprocessing; pinning the first attempt excludes retry loops
-            # + backoff. Logging object only — must NOT go into
-            # litellm_params["metadata"] (caller request metadata, typed
-            # Dict[str, str], echoed downstream; a datetime breaks it).
-            if self.model_call_details.get("first_api_call_start_time") is None:
-                self.model_call_details["first_api_call_start_time"] = self.model_call_details["api_call_start_time"]
+            # A proxy-gate failure (auth, rate limit, client disconnect) fires pre_call for its callbacks
+            # without any provider handoff, so it must not stamp the handoff instants.
+            if LITELLM_LOGGING_NO_UPSTREAM_LLM_CALL not in self.model_call_details:
+                self.model_call_details["api_call_start_time"] = datetime.datetime.now()
+                # Set-once first provider-handoff instant. api_call_start_time
+                # is overwritten on every retry, so it can't measure one-time
+                # preprocessing; pinning the first attempt excludes retry loops
+                # + backoff. Logging object only — must NOT go into
+                # litellm_params["metadata"] (caller request metadata, typed
+                # Dict[str, str], echoed downstream; a datetime breaks it).
+                if self.model_call_details.get("first_api_call_start_time") is None:
+                    self.model_call_details["first_api_call_start_time"] = self.model_call_details[
+                        "api_call_start_time"
+                    ]
             # Input Integration Logging -> If you want to log the fact that an attempt to call the model was made
             callbacks: Final = litellm.input_callback + (self.dynamic_input_callbacks or [])
             for callback in callbacks:

tests/unit/litellm_core_utils/test_litellm_logging.py

@@ -32,6 +32,7 @@ from litellm._service_logger import ServiceLogging
 from litellm.caching.caching import DualCache
 from litellm.constants import (
     KUBERNETES_POD_ROUTING_KEY,
+    LITELLM_LOGGING_NO_UPSTREAM_LLM_CALL,
     LOGGING_WORKER_MAX_TIME_PER_COROUTINE,
     REDACTED_BY_LITELLM,
     SENTRY_PII_DENYLIST,
@@ -408,6 +409,20 @@ def test_get_masked_api_base(logging_obj):
     assert type(masked_api_base) == str
 
 
+@pytest.mark.parametrize("no_upstream_call", [False, True])
+def test_pre_call_stamps_the_provider_handoff_only_when_a_provider_call_is_made(logging_obj, no_upstream_call):
+    """The proxy fires pre_call for a failure it raised itself (auth, rate limit, client disconnect)
+    so callbacks see it; that call never reached a provider, so neither handoff instant may be set."""
+    logging_obj.update_environment_variables(litellm_params={}, optional_params={})
+    if no_upstream_call:
+        logging_obj.model_call_details[LITELLM_LOGGING_NO_UPSTREAM_LLM_CALL] = True
+
+    logging_obj.pre_call(input="", api_key="")
+
+    assert ("api_call_start_time" in logging_obj.model_call_details) is not no_upstream_call
+    assert (logging_obj.model_call_details.get("first_api_call_start_time") is not None) is not no_upstream_call
+
+
 def test_pre_call_tolerates_missing_api_base(logging_obj):
     """Presigned batch retrieves (Mistral, Bedrock) build their own URL and pass api_base=None
     to pre_call; masking must not raise or the request's pre-call logging is silently lost."""

tests/unit/proxy/test_proxy_utils_model_creation_and_error_logging.py

@@ -444,6 +444,47 @@ class TestPostCallFailureHookLiftsFirstApiCallStartTime:
         assert "litellm_logging_obj" not in request_data
 
 
+class TestPostCallFailureHookDoesNotInventAProviderHandoff:
+    """A failure the proxy raised before any provider call (here an auth error) is logged through
+    _handle_logging_proxy_only_error, which fires pre_call for the callbacks. That must not stamp a
+    handoff instant onto the request, or every downstream reader (preprocessing latency, the
+    dispatched check behind the failure-row estimate) sees a provider call that never happened."""
+
+    @pytest.mark.asyncio
+    async def test_proxy_only_failure_lifts_no_first_api_call_start_time(self):
+        from datetime import datetime
+        from unittest.mock import AsyncMock, patch
+
+        from litellm.litellm_core_utils.litellm_logging import Logging
+        from litellm.proxy._types import ProxyErrorTypes, UserAPIKeyAuth
+
+        logging_obj = Logging(
+            model="gpt-4.1",
+            messages=[{"role": "user", "content": "hi"}],
+            stream=False,
+            call_type="acompletion",
+            start_time=datetime.now(),
+            litellm_call_id="pre-handoff-auth-failure",
+            function_id="pre-handoff",
+        )
+        request_data: Final[dict[str, object]] = {"litellm_logging_obj": logging_obj, "model": "gpt-4.1", "metadata": {}}
+        proxy_logging_obj = ProxyLogging(user_api_key_cache=DualCache())
+        proxy_logging_obj.alert_types = []
+        with (
+            patch.object(proxy_logging_obj, "update_request_status", new=AsyncMock()),
+            patch.object(proxy_logging_obj, "_dispatch_proxy_only_failure_handlers", new=AsyncMock()),
+        ):
+            await proxy_logging_obj.post_call_failure_hook(
+                request_data=request_data,
+                original_exception=Exception("Authentication Error, invalid key"),
+                user_api_key_dict=UserAPIKeyAuth(request_route="/v1/chat/completions"),
+                error_type=ProxyErrorTypes.auth_error,
+            )
+
+        assert request_data.get("first_api_call_start_time") is None
+        assert "api_call_start_time" not in logging_obj.model_call_details
+
+
 class TestPostCallFailureHookLiftsRecoveredPartialSpend:
     """A stream that broke mid-flight still billed the provider for the chunks
     already delivered. The streaming handler stashes that recovered usage and