mirror of
https://github.com/BerriAI/litellm.git
synced 2026-09-14 23:21:35 +00:00
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>
This commit is contained in:
Devin AI
parent
60729f733e
commit
c5fc864eb0
3 changed files with 201 additions and 66 deletions
|
|
@ -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():
|
||||
|
|
|
|||
|
|
@ -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)}")
|
||||
|
|
|
|||
154
tests/test_litellm/proxy/common_utils/test_debug_utils.py
Normal file
154
tests/test_litellm/proxy/common_utils/test_debug_utils.py
Normal file
|
|
@ -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,
|
||||
}
|
||||
Loading…
Add table
Reference in a new issue