diff --git a/litellm/litellm_core_utils/health_check_helpers.py b/litellm/litellm_core_utils/health_check_helpers.py index a0f027cd58f..a92524f927b 100644 --- a/litellm/litellm_core_utils/health_check_helpers.py +++ b/litellm/litellm_core_utils/health_check_helpers.py @@ -80,6 +80,14 @@ class HealthCheckHelpers: 1. `tags`: This helps identify health check calls in the DB. 2. `user_api_key_auth`: This helps identify health check calls in the DB. We need this since the DB requires an API Key to track a log in the SpendLogs Table + 3. `no-log`: Health checks are infrastructure probes, not user + traffic, so their requests must not be routed through user + logging integrations. Without this, a deployment whose host is + offline emits a full connection-error traceback through the + logging callbacks on every poll cycle (see issue #34281). + `no-log` skips those user callbacks while proxy cost/DB + callbacks still run (see Logging.should_run_callback), so + health state is still recorded. """ from litellm.proxy._types import UserAPIKeyAuth from litellm.proxy.litellm_pre_call_utils import LiteLLMProxyRequestSetup @@ -87,6 +95,7 @@ class HealthCheckHelpers: _metadata_variable_name: Final = "litellm_metadata" litellm_metadata: Final = HealthCheckHelpers._get_metadata_for_health_check_call() model_params[_metadata_variable_name] = litellm_metadata + model_params["no-log"] = True model_params = LiteLLMProxyRequestSetup.add_user_api_key_auth_to_request_metadata( data=model_params, user_api_key_dict=UserAPIKeyAuth.get_litellm_internal_health_check_user_api_key_auth(), diff --git a/litellm/proxy/health_check.py b/litellm/proxy/health_check.py index a7a541560f2..071e353f014 100644 --- a/litellm/proxy/health_check.py +++ b/litellm/proxy/health_check.py @@ -13,6 +13,7 @@ from typing import TYPE_CHECKING, Final, TypeVar from pydantic import TypeAdapter, ValidationError +import httpx import litellm if TYPE_CHECKING: @@ -153,6 +154,172 @@ def _clean_endpoint_data(endpoint_data: dict, details: bool | None = True): return {k: v for k, v in endpoint_data.items() if k in displayed} +# --------------------------------------------------------------------------- +# Deployment reachability state tracking (issue #34281) +# +# A deployment whose host is offline used to emit a full stack trace on every +# background health-check poll. We track reachability per deployment id and log +# a single line when the state changes: one WARNING on healthy -> unhealthy and +# one INFO on unhealthy -> healthy. A still-unhealthy deployment is not re-logged +# every cycle, so an ad-hoc host that is offline by design stays quiet until it +# recovers. +# --------------------------------------------------------------------------- + +# deployment_id -> {"reachable": bool, "since": float, "last_logged": float} +_deployment_reachability_state: dict = {} + +# Re-emit a one-line "still unreachable" WARNING at most once per this many +# seconds while a deployment stays down. 0 (default) means log on transition +# only. Override via ``litellm.health_check_unreachable_relog_seconds``. +_DEFAULT_UNREACHABLE_RELOG_SECONDS = 0.0 + + +def _health_unreachable_relog_seconds() -> float: + value = getattr(litellm, "health_check_unreachable_relog_seconds", None) + if value is None: + return _DEFAULT_UNREACHABLE_RELOG_SECONDS + try: + return max(0.0, float(value)) + except (TypeError, ValueError): + return _DEFAULT_UNREACHABLE_RELOG_SECONDS + + +def _deployment_label(endpoint: dict) -> str: + """Human-readable identifier for a deployment in health-check logs.""" + model = endpoint.get("model") or endpoint.get("model_name") or endpoint.get("model_id") or "unknown" + api_base = endpoint.get("api_base") + return f"{model} ({api_base})" if api_base else str(model) + + +def _short_error(exc: BaseException | None) -> str: + """First line of an exception, bounded, for a single-line health log.""" + if exc is None: + return "unknown error" + text = str(exc).strip() + if not text: + return exc.__class__.__name__ + return text.splitlines()[0][:200] + + +def _is_transport_error(exc: BaseException | None) -> bool: + """ + True when the failure means the provider is unreachable (connection refused, + DNS failure, TLS error, timeout) rather than a real error returned by the + provider. An unreachable host is a degraded state, so we log it as a concise + WARNING; a real provider error keeps its full detail. + """ + if exc is None: + return False + if isinstance(exc, (ConnectionError, TimeoutError, OSError, httpx.TransportError)): + return True + for attr in ("APIConnectionError", "Timeout", "ServiceUnavailableError"): + litellm_exc = getattr(litellm, attr, None) + if litellm_exc is not None and isinstance(exc, litellm_exc): + return True + text = f"{exc.__class__.__name__} {exc}".lower() + return any( + signature in text + for signature in ( + "connection refused", + "connect call failed", + "cannot connect", + "name or service not known", + "temporary failure in name resolution", + "network is unreachable", + "no route to host", + "timed out", + "timeout", + ) + ) + + +def _log_deployment_health_transitions( + healthy_endpoints: list, + unhealthy_endpoints: list, + exceptions_by_model_id: dict, +) -> None: + """ + Log one line per deployment reachability transition instead of a stack trace + per poll cycle. Intended for the background health loop. Never raises. + """ + now = time.monotonic() + relog_seconds = _health_unreachable_relog_seconds() + + for endpoint in healthy_endpoints: + model_id = endpoint.get("model_id") + if not model_id: + continue + previous = _deployment_reachability_state.get(model_id) + if previous is not None and not previous.get("reachable", True): + logger.info( + "health_check: deployment %s is reachable again", + _deployment_label(endpoint), + ) + _deployment_reachability_state[model_id] = { + "reachable": True, + "since": now, + "last_logged": now, + } + + for endpoint in unhealthy_endpoints: + model_id = endpoint.get("model_id") + if not model_id: + continue + exc = exceptions_by_model_id.get(model_id) + previous = _deployment_reachability_state.get(model_id) + + # `previous is None` in the condition narrows `previous` to a dict in the + # else branch below, so the state updates there are not Optional access. + if previous is None or previous.get("reachable", True): + if _is_transport_error(exc): + logger.warning( + "health_check: deployment %s is unreachable (%s); suppressing per-cycle logs until it recovers", + _deployment_label(endpoint), + _short_error(exc), + ) + else: + logger.warning( + "health_check: deployment %s failed its health check: %s", + _deployment_label(endpoint), + _short_error(exc), + ) + _deployment_reachability_state[model_id] = { + "reachable": False, + "since": now, + "last_logged": now, + } + else: + last_logged = previous.get("last_logged", previous.get("since", now)) + if relog_seconds and (now - last_logged) >= relog_seconds: + logger.warning( + "health_check: deployment %s still unreachable after %.0fs", + _deployment_label(endpoint), + now - previous.get("since", now), + ) + previous["last_logged"] = now + previous["reachable"] = False + _deployment_reachability_state[model_id] = previous + + +def _maybe_log_health_transitions( + source: str, + healthy_endpoints: list, + unhealthy_endpoints: list, + exceptions_by_model_id: dict, +) -> None: + """ + Gate transition logging to the recurring background poll (so an on-demand + /health call does not mutate the shared reachability state) and never let a + logging error break the health cycle. + """ + if source != "proxy_background_loop": + return + try: + _log_deployment_health_transitions(healthy_endpoints, unhealthy_endpoints, exceptions_by_model_id) + except Exception: # noqa: BLE001 + logger.debug("health_check: transition logging failed", exc_info=True) + + def health_check_filter_kwargs_from_general_settings( general_settings: dict | None, ) -> dict: @@ -976,4 +1143,8 @@ async def perform_health_check( _rss_mb_for_log(), ) + # Emit one log line per reachability transition (down/up) for the recurring + # background poll, instead of a stack trace per cycle (issue #34281). + _maybe_log_health_transitions(source, healthy_endpoints, unhealthy_endpoints, exceptions_by_model_id) + return healthy_endpoints, unhealthy_endpoints, exceptions_by_model_id diff --git a/tests/test_litellm/proxy/test_health_check_transition_logging.py b/tests/test_litellm/proxy/test_health_check_transition_logging.py new file mode 100644 index 00000000000..034c7db6787 --- /dev/null +++ b/tests/test_litellm/proxy/test_health_check_transition_logging.py @@ -0,0 +1,188 @@ +""" +Tests for health-check reachability transition logging and the no-log flag on +internal health probes (issue #34281): an offline deployment should produce a +single log line per state change instead of a full stack trace per poll cycle, +and health probes should not be routed through user logging callbacks. +""" + +import logging +import os +import sys + +import httpx +import pytest + +sys.path.insert(0, os.path.abspath("../../..")) + +import litellm +from litellm.litellm_core_utils.health_check_helpers import HealthCheckHelpers +from litellm.proxy import health_check as hc + + +@pytest.fixture(autouse=True) +def _reset_reachability_state(): + """Isolate the module-level reachability state between tests.""" + hc._deployment_reachability_state.clear() + if hasattr(litellm, "health_check_unreachable_relog_seconds"): + delattr(litellm, "health_check_unreachable_relog_seconds") + yield + hc._deployment_reachability_state.clear() + + +# --------------------------------------------------------------------------- +# no-log flag on internal health probes +# --------------------------------------------------------------------------- + + +def test_health_check_tracking_sets_no_log(): + """Health probes must be marked no-log so failures skip user logging + callbacks (proxy cost/DB callbacks still run).""" + updated = HealthCheckHelpers._update_model_params_with_health_check_tracking_information( + model_params={"model": "gpt-4", "api_base": "http://localhost:1234"} + ) + assert updated["no-log"] is True + + +# --------------------------------------------------------------------------- +# transport-error classification +# --------------------------------------------------------------------------- + + +@pytest.mark.parametrize( + "exc,expected", + [ + (ConnectionRefusedError("[Errno 111] Connection refused"), True), + (httpx.ConnectError("Cannot connect to host"), True), + (httpx.ConnectTimeout("timed out"), True), + (TimeoutError(), True), + (OSError("Network is unreachable"), True), + (Exception("AuthenticationError: invalid api key - status 401"), False), + (Exception("BadRequestError: unsupported parameter"), False), + (None, False), + ], +) +def test_is_transport_error_classification(exc, expected): + assert hc._is_transport_error(exc) is expected + + +# --------------------------------------------------------------------------- +# transition logging: down -> quiet -> up +# --------------------------------------------------------------------------- + + +def _unhealthy(model_id="d1"): + return [{"model_id": model_id, "model": "qwen3", "api_base": "http://ollama:8443"}] + + +def _healthy(model_id="d1"): + return [{"model_id": model_id, "model": "qwen3", "api_base": "http://ollama:8443"}] + + +def _warnings(caplog): + return [r for r in caplog.records if r.levelno == logging.WARNING] + + +def _infos(caplog): + return [r for r in caplog.records if r.levelno == logging.INFO] + + +def test_first_failure_logs_single_warning(caplog): + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + exc = ConnectionRefusedError("[Errno 111] Connection refused") + + hc._log_deployment_health_transitions( + healthy_endpoints=[], + unhealthy_endpoints=_unhealthy(), + exceptions_by_model_id={"d1": exc}, + ) + + warnings = _warnings(caplog) + assert len(warnings) == 1 + msg = warnings[0].getMessage() + assert "unreachable" in msg + assert "qwen3" in msg and "http://ollama:8443" in msg + assert hc._deployment_reachability_state["d1"]["reachable"] is False + + +def test_still_unhealthy_does_not_relog(caplog): + exc = ConnectionRefusedError("[Errno 111] Connection refused") + # cycle 1: transition down + hc._log_deployment_health_transitions([], _unhealthy(), {"d1": exc}) + + # cycle 2: still down -> must be silent with default relog (0) + caplog.clear() + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + hc._log_deployment_health_transitions([], _unhealthy(), {"d1": exc}) + + assert _warnings(caplog) == [] + + +def test_recovery_logs_single_info(caplog): + exc = ConnectionRefusedError("[Errno 111] Connection refused") + hc._log_deployment_health_transitions([], _unhealthy(), {"d1": exc}) + + caplog.clear() + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + hc._log_deployment_health_transitions(_healthy(), [], {}) + + infos = _infos(caplog) + assert len(infos) == 1 + assert "reachable again" in infos[0].getMessage() + assert hc._deployment_reachability_state["d1"]["reachable"] is True + + +def test_real_error_keeps_detail(caplog): + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + exc = Exception("AuthenticationError: invalid api key - status 401") + + hc._log_deployment_health_transitions([], _unhealthy(), {"d1": exc}) + + warnings = _warnings(caplog) + assert len(warnings) == 1 + msg = warnings[0].getMessage() + assert "failed its health check" in msg + assert "invalid api key" in msg + + +def test_relog_cooldown_reemits_after_interval(caplog): + litellm.health_check_unreachable_relog_seconds = 1 + exc = ConnectionRefusedError("[Errno 111] Connection refused") + # transition down + hc._log_deployment_health_transitions([], _unhealthy(), {"d1": exc}) + + # simulate the cooldown having elapsed + hc._deployment_reachability_state["d1"]["last_logged"] -= 100 + + caplog.clear() + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + hc._log_deployment_health_transitions([], _unhealthy(), {"d1": exc}) + + warnings = _warnings(caplog) + assert len(warnings) == 1 + assert "still unreachable" in warnings[0].getMessage() + + +def test_maybe_log_gated_to_background_loop(caplog): + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + exc = ConnectionRefusedError("[Errno 111] Connection refused") + + # on-demand /health source: must not log or touch shared state + hc._maybe_log_health_transitions("endpoint", [], _unhealthy(), {"d1": exc}) + assert _warnings(caplog) == [] + assert hc._deployment_reachability_state == {} + + # background loop source: logs and records state + hc._maybe_log_health_transitions("proxy_background_loop", [], _unhealthy(), {"d1": exc}) + assert len(_warnings(caplog)) == 1 + assert hc._deployment_reachability_state["d1"]["reachable"] is False + + +def test_endpoint_without_model_id_is_ignored(caplog): + caplog.set_level(logging.INFO, logger="litellm.proxy.health_check") + hc._log_deployment_health_transitions( + healthy_endpoints=[], + unhealthy_endpoints=[{"model": "no-id"}], + exceptions_by_model_id={}, + ) + assert _warnings(caplog) == [] + assert hc._deployment_reachability_state == {}