From c5fc864eb0db3bc3d004c63853b5539d5d5e7eda Mon Sep 17 00:00:00 2001 From: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> Date: Thu, 9 Jul 2026 17:21:48 +0000 Subject: [PATCH] fix(proxy): honor LITELLM_LOG for all verbose loggers on startup init_verbose_loggers short-circuited before reading LITELLM_LOG whenever WORKER_CONFIG held a config file path (the K8s/Helm shape) and, even on the JSON shape, only raised the router and proxy loggers. That left the core LiteLLM package logger at WARNING, so LITELLM_LOG=DEBUG produced no useful debug output on Helm deployments. Co-Authored-By: Ishaan Jaffer <155045088+ishaan-berri@users.noreply.github.com> --- litellm/_logging.py | 17 +- litellm/proxy/common_utils/debug_utils.py | 96 ++++------- .../proxy/common_utils/test_debug_utils.py | 154 ++++++++++++++++++ 3 files changed, 201 insertions(+), 66 deletions(-) create mode 100644 tests/test_litellm/proxy/common_utils/test_debug_utils.py diff --git a/litellm/_logging.py b/litellm/_logging.py index 5f3c483869d..2d508dcf226 100644 --- a/litellm/_logging.py +++ b/litellm/_logging.py @@ -391,10 +391,21 @@ def _turn_on_json(): _setup_json_exception_handlers(JsonFormatter()) +def set_verbose_loggers_level(level: int) -> None: + """Set the package, router, and proxy verbose loggers to the same level. + + Keeping all three in lockstep is intentional: skipping ``verbose_logger`` + (the core "LiteLLM" package logger) silently drops the bulk of debug output + (raw request/response, cost tracking, provider calls) even when the router + and proxy loggers are turned up. + """ + verbose_logger.setLevel(level=level) # set package log level + verbose_router_logger.setLevel(level=level) # set router log level + verbose_proxy_logger.setLevel(level=level) # set proxy log level + + def _turn_on_debug(): - verbose_logger.setLevel(level=logging.DEBUG) # set package log to debug - verbose_router_logger.setLevel(level=logging.DEBUG) # set router logs to debug - verbose_proxy_logger.setLevel(level=logging.DEBUG) # set proxy logs to debug + set_verbose_loggers_level(logging.DEBUG) def _disable_debugging(): diff --git a/litellm/proxy/common_utils/debug_utils.py b/litellm/proxy/common_utils/debug_utils.py index aed3e1228f1..03171d3f98d 100644 --- a/litellm/proxy/common_utils/debug_utils.py +++ b/litellm/proxy/common_utils/debug_utils.py @@ -714,73 +714,43 @@ async def get_otel_spans(): } +def _worker_config_debug_flags() -> Tuple[Optional[bool], Optional[bool]]: + """Read the ``debug``/``detailed_debug`` CLI flags out of ``WORKER_CONFIG``. + + Those flags only exist when the CLI serialized its arguments into a JSON + blob. The file-path shape (``WORKER_CONFIG`` pointing at a config yaml) and + the missing shape carry no such flags, so both yield ``(None, None)`` and + logging falls back to the ``LITELLM_LOG`` env var. + """ + worker_config = get_secret_str("WORKER_CONFIG") + if worker_config is None or os.path.isfile(worker_config): + return None, None + settings = json.loads(worker_config) + if not isinstance(settings, dict): + return None, None + return settings.get("debug"), settings.get("detailed_debug") + + # Helper functions for debugging def init_verbose_loggers(): + import logging + + from litellm._logging import set_verbose_loggers_level + try: - worker_config = get_secret_str("WORKER_CONFIG") - # if not, assume it's a json string - if worker_config is None: - return - if os.path.isfile(worker_config): - return - _settings = json.loads(worker_config) - if not isinstance(_settings, dict): - return - - debug = _settings.get("debug", None) - detailed_debug = _settings.get("detailed_debug", None) - if debug is True: # this needs to be first, so users can see Router init debugg - import logging - - from litellm._logging import ( - verbose_logger, - verbose_proxy_logger, - verbose_router_logger, - ) - - # this must ALWAYS remain logging.INFO, DO NOT MODIFY THIS - verbose_logger.setLevel(level=logging.INFO) # sets package logs to info - verbose_router_logger.setLevel(level=logging.INFO) # set router logs to info - verbose_proxy_logger.setLevel(level=logging.INFO) # set proxy logs to info + debug, detailed_debug = _worker_config_debug_flags() if detailed_debug is True: - import logging - - from litellm._logging import ( - verbose_logger, - verbose_proxy_logger, - verbose_router_logger, - ) - - verbose_logger.setLevel(level=logging.DEBUG) # set package log to debug - verbose_router_logger.setLevel(level=logging.DEBUG) # set router logs to debug - verbose_proxy_logger.setLevel(level=logging.DEBUG) # set proxy logs to debug - elif debug is False and detailed_debug is False: + set_verbose_loggers_level(logging.DEBUG) + elif debug is True: + # this must ALWAYS remain logging.INFO, DO NOT MODIFY THIS + set_verbose_loggers_level(logging.INFO) + else: # users can control proxy debugging using env variable = 'LITELLM_LOG' - litellm_log_setting = os.environ.get("LITELLM_LOG", "") - if litellm_log_setting is not None: - if litellm_log_setting.upper() == "INFO": - import logging - - from litellm._logging import ( - verbose_proxy_logger, - verbose_router_logger, - ) - - # this must ALWAYS remain logging.INFO, DO NOT MODIFY THIS - - verbose_router_logger.setLevel(level=logging.INFO) # set router logs to info - verbose_proxy_logger.setLevel(level=logging.INFO) # set proxy logs to info - elif litellm_log_setting.upper() == "DEBUG": - import logging - - from litellm._logging import ( - verbose_proxy_logger, - verbose_router_logger, - ) - - verbose_router_logger.setLevel(level=logging.DEBUG) # set router logs to info - verbose_proxy_logger.setLevel(level=logging.DEBUG) # set proxy logs to debug + litellm_log_setting = os.environ.get("LITELLM_LOG", "").upper() + if litellm_log_setting == "DEBUG": + set_verbose_loggers_level(logging.DEBUG) + elif litellm_log_setting == "INFO": + # this must ALWAYS remain logging.INFO, DO NOT MODIFY THIS + set_verbose_loggers_level(logging.INFO) except Exception as e: - import logging - logging.warning(f"Failed to init verbose loggers: {str(e)}") diff --git a/tests/test_litellm/proxy/common_utils/test_debug_utils.py b/tests/test_litellm/proxy/common_utils/test_debug_utils.py new file mode 100644 index 00000000000..67bc3a6ddd3 --- /dev/null +++ b/tests/test_litellm/proxy/common_utils/test_debug_utils.py @@ -0,0 +1,154 @@ +import json +import logging +import os +import sys + +import pytest + +sys.path.insert(0, os.path.abspath("../../../../..")) + +from litellm._logging import ( + verbose_logger, + verbose_proxy_logger, + verbose_router_logger, +) +from litellm.proxy.common_utils.debug_utils import init_verbose_loggers + +_ALL_VERBOSE_LOGGERS = (verbose_logger, verbose_router_logger, verbose_proxy_logger) + + +@pytest.fixture(autouse=True) +def _reset_verbose_logger_levels(): + """init_verbose_loggers mutates process-global logger levels; snapshot and + restore so tests can't leak state into each other.""" + saved = [lg.level for lg in _ALL_VERBOSE_LOGGERS] + for lg in _ALL_VERBOSE_LOGGERS: + lg.setLevel(logging.NOTSET) + try: + yield + finally: + for lg, level in zip(_ALL_VERBOSE_LOGGERS, saved): + lg.setLevel(level) + + +def _effective_levels(): + return {lg.name: lg.getEffectiveLevel() for lg in _ALL_VERBOSE_LOGGERS} + + +def _worker_config_json(): + """The shape the litellm CLI writes: a JSON blob with debug flags off.""" + return json.dumps( + {"model": None, "debug": False, "detailed_debug": False, "config": "/etc/litellm/config.yaml"} + ) + + +def test_litellm_log_debug_json_worker_config_sets_all_loggers(monkeypatch): + monkeypatch.setenv("LITELLM_LOG", "DEBUG") + monkeypatch.setenv("WORKER_CONFIG", _worker_config_json()) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.DEBUG, + "LiteLLM Router": logging.DEBUG, + "LiteLLM Proxy": logging.DEBUG, + } + + +def test_litellm_log_debug_file_worker_config_sets_all_loggers(monkeypatch, tmp_path): + """K8s/Helm hand the proxy a config file path via WORKER_CONFIG. That shape + used to short-circuit init_verbose_loggers before LITELLM_LOG was read, so + LITELLM_LOG=DEBUG produced no debug logs at all.""" + config_file = tmp_path / "config.yaml" + config_file.write_text("model_list: []\n") + monkeypatch.setenv("LITELLM_LOG", "DEBUG") + monkeypatch.setenv("WORKER_CONFIG", str(config_file)) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.DEBUG, + "LiteLLM Router": logging.DEBUG, + "LiteLLM Proxy": logging.DEBUG, + } + + +def test_litellm_log_debug_without_worker_config_sets_all_loggers(monkeypatch): + monkeypatch.setenv("LITELLM_LOG", "DEBUG") + monkeypatch.delenv("WORKER_CONFIG", raising=False) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.DEBUG, + "LiteLLM Router": logging.DEBUG, + "LiteLLM Proxy": logging.DEBUG, + } + + +def test_litellm_log_debug_turns_on_core_package_logger(monkeypatch): + """Regression for the omitted core logger: LITELLM_LOG=DEBUG used to raise + only the router/proxy loggers, leaving the "LiteLLM" package logger (which + emits raw request/response, cost tracking, provider calls) at WARNING.""" + monkeypatch.setenv("LITELLM_LOG", "DEBUG") + monkeypatch.setenv("WORKER_CONFIG", _worker_config_json()) + + init_verbose_loggers() + + assert verbose_logger.isEnabledFor(logging.DEBUG) + + +def test_litellm_log_info_sets_all_loggers_to_info(monkeypatch): + monkeypatch.setenv("LITELLM_LOG", "INFO") + monkeypatch.setenv("WORKER_CONFIG", _worker_config_json()) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.INFO, + "LiteLLM Router": logging.INFO, + "LiteLLM Proxy": logging.INFO, + } + + +def test_detailed_debug_flag_wins_over_env(monkeypatch): + monkeypatch.setenv("LITELLM_LOG", "INFO") + monkeypatch.setenv( + "WORKER_CONFIG", json.dumps({"debug": False, "detailed_debug": True}) + ) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.DEBUG, + "LiteLLM Router": logging.DEBUG, + "LiteLLM Proxy": logging.DEBUG, + } + + +def test_debug_flag_sets_info(monkeypatch): + monkeypatch.delenv("LITELLM_LOG", raising=False) + monkeypatch.setenv( + "WORKER_CONFIG", json.dumps({"debug": True, "detailed_debug": False}) + ) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.INFO, + "LiteLLM Router": logging.INFO, + "LiteLLM Proxy": logging.INFO, + } + + +def test_no_flags_and_no_env_leaves_loggers_untouched(monkeypatch): + monkeypatch.delenv("LITELLM_LOG", raising=False) + monkeypatch.delenv("WORKER_CONFIG", raising=False) + + init_verbose_loggers() + + assert _effective_levels() == { + "LiteLLM": logging.WARNING, + "LiteLLM Router": logging.WARNING, + "LiteLLM Proxy": logging.WARNING, + }