fix(router): time fallback-hop 408s against now, not the previous hop's end_time

The failure logger skips fallback hops (has_logged_async_failure is already set), so
model_call_details.end_time still belongs to the previous hop and predates this hop's
api_call_start_time. The fallback cooldown guard measured a negative elapsed time and
cooled down deployments for caller-set timeouts.

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>
This commit is contained in:
yassin 2026-09-15 20:56:33 +00:00
parent 2f719fec52
commit 595bec46ff
3 changed files with 22 additions and 8 deletions

View file

@ -640,8 +640,13 @@ def cast_exception_status_to_int(exception_status: str | int) -> int:
return exception_status
def is_caller_timeout_408(model_call_details: Mapping[str, object], exception_status: str | int) -> bool:
"""A 408 that arrives before the caller-set timeout could have fired came from the provider."""
def is_caller_timeout_408(
model_call_details: Mapping[str, object], exception_status: str | int, ended: datetime | None = None
) -> bool:
"""A 408 that arrives before the caller-set timeout could have fired came from the provider.
``ended`` overrides ``model_call_details["end_time"]`` for callers that run before the
failure logger has stamped the current API call's end time."""
if cast_exception_status_to_int(exception_status) != 408:
return False
litellm_params: Final = model_call_details.get("litellm_params")
@ -649,7 +654,7 @@ def is_caller_timeout_408(model_call_details: Mapping[str, object], exception_st
return False
timeout: Final = litellm_params.get("timeout")
started: Final = model_call_details.get("api_call_start_time") or model_call_details.get("start_time")
ended: Final = model_call_details.get("end_time")
if not isinstance(timeout, (int, float)) or not isinstance(started, datetime) or not isinstance(ended, datetime):
finished: Final = ended if ended is not None else model_call_details.get("end_time")
if not isinstance(timeout, (int, float)) or not isinstance(started, datetime) or not isinstance(finished, datetime):
return False
return (ended - started).total_seconds() >= timeout
return (finished - started).total_seconds() >= timeout

View file

@ -2,6 +2,7 @@ import hashlib
import json
from collections.abc import Mapping, Sequence
from dataclasses import dataclass
from datetime import datetime
from enum import Enum
from types import MappingProxyType
from typing import TYPE_CHECKING, Any, Final
@ -84,7 +85,11 @@ def _trigger_cooldown_for_failed_deployment(
# timeout, which litellm.Timeout reports as status 408 regardless of the deployment's
# actual health. Left unguarded, a caller could force a 408 on every deployment in
# the fallback chain from a single request with a near-zero timeout.
if is_caller_timeout_408(model_call_details, exception_status):
if is_caller_timeout_408(
model_call_details,
exception_status,
ended=datetime.now(), # noqa: DTZ005 # naive to match the logging pipeline's api_call_start_time
):
verbose_router_logger.debug(
"Not triggering cooldown for fallback deployment: a caller-supplied "
"x-litellm-timeout caused this 408, not deployment health."

View file

@ -956,7 +956,11 @@ class TestTriggerCooldownForFailedDeployment:
"""The proxy's x-litellm-timeout header lets a caller set an arbitrarily short
timeout, which litellm.Timeout reports as status 408 regardless of the
deployment's actual health. Without this guard, a caller could force a 408 on
every deployment in the fallback chain from a single request."""
every deployment in the fallback chain from a single request.
The failure logger never stamps end_time for a fallback hop (has_logged_async_failure
is already set), so model_call_details still carries the previous hop's end_time, which
predates this hop's api_call_start_time. The guard must not trust it."""
mock_router = MagicMock()
mock_router.cooldown_time = 60.0
mock_router.get_model_info.return_value = None
@ -977,7 +981,7 @@ class TestTriggerCooldownForFailedDeployment:
model_call_details={
"litellm_params": {"client_side_timeout": True, "timeout": 0.5},
"api_call_start_time": datetime.now() - timedelta(seconds=1),
"end_time": datetime.now(),
"end_time": datetime.now() - timedelta(seconds=5),
},
)