fix(proxy): resolve LITELLM_LOG for uvicorn at startup and restore logger state in tests

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>

litellm-proxy-extras/tests/test_logging.py

@@ -1,34 +1,37 @@
 import importlib
 import logging
+from collections.abc import Iterator
 
 import pytest
 
 import litellm_proxy_extras._logging as extras_logging
 
 
-def test_litellm_log_error_silences_extras_info_lines(monkeypatch):
-    saved_handlers = logging.getLogger("litellm_proxy_extras").handlers[:]
-    monkeypatch.setenv("LITELLM_LOG", "ERROR")
-    logging.getLogger("litellm_proxy_extras").handlers[:] = []
+@pytest.fixture
+def fresh_extras_logger() -> Iterator[logging.Logger]:
+    logger = logging.getLogger("litellm_proxy_extras")
+    saved_handlers = logger.handlers[:]
+    saved_level = logger.level
+    logger.handlers[:] = []
     try:
-        reloaded = importlib.reload(extras_logging).logger
-        assert reloaded.isEnabledFor(logging.INFO) is False
-        assert reloaded.isEnabledFor(logging.ERROR) is True
+        yield logger
     finally:
-        logging.getLogger("litellm_proxy_extras").handlers[:] = saved_handlers
-        logging.getLogger("litellm_proxy_extras").setLevel(logging.INFO)
+        logger.handlers[:] = saved_handlers
+        logger.setLevel(saved_level)
+
+
+def test_litellm_log_error_silences_extras_info_lines(monkeypatch, fresh_extras_logger):
+    monkeypatch.setenv("LITELLM_LOG", "ERROR")
+    reloaded = importlib.reload(extras_logging).logger
+    assert reloaded is fresh_extras_logger
+    assert reloaded.isEnabledFor(logging.INFO) is False
+    assert reloaded.isEnabledFor(logging.ERROR) is True
 
 
 @pytest.mark.parametrize("litellm_log", [None, "info", "DEBUG"])
-def test_unset_or_verbose_litellm_log_keeps_extras_info_lines(monkeypatch, litellm_log):
-    saved_handlers = logging.getLogger("litellm_proxy_extras").handlers[:]
+def test_unset_or_verbose_litellm_log_keeps_extras_info_lines(monkeypatch, fresh_extras_logger, litellm_log):
     if litellm_log is None:
         monkeypatch.delenv("LITELLM_LOG", raising=False)
     else:
         monkeypatch.setenv("LITELLM_LOG", litellm_log)
-    logging.getLogger("litellm_proxy_extras").handlers[:] = []
-    try:
-        assert importlib.reload(extras_logging).logger.isEnabledFor(logging.INFO) is True
-    finally:
-        logging.getLogger("litellm_proxy_extras").handlers[:] = saved_handlers
-        logging.getLogger("litellm_proxy_extras").setLevel(logging.INFO)
+    assert importlib.reload(extras_logging).logger.isEnabledFor(logging.INFO) is True

litellm/_logging.py

@@ -401,10 +401,14 @@ def _parse_json_logs_env(value: str | None) -> bool:
     return (value or "").lower() == "true"
 
 
+def resolve_log_level(log_level: str) -> int:
+    return getattr(logging, log_level.upper())
+
+
 json_logs: Final = _parse_json_logs_env(os.getenv("JSON_LOGS"))
 # Create a handler for the logger (you may need to adapt this based on your needs)
 log_level: Final = os.getenv("LITELLM_LOG", "DEBUG")
-numeric_level: Final[int] = getattr(logging, log_level.upper())
+numeric_level: Final[int] = resolve_log_level(log_level)
 handler: Final = LevelRoutingStreamHandler()
 handler.setLevel(numeric_level)
 handler.addFilter(_secret_filter)

litellm/proxy/proxy_cli.py

@@ -261,7 +261,7 @@ class ProxyInitializationHelpers:
         import uvicorn
 
         import litellm
-        from litellm._logging import _get_uvicorn_json_log_config, numeric_level
+        from litellm._logging import _get_uvicorn_json_log_config, resolve_log_level
 
         uvicorn_args: Final = {
             "app": "litellm.proxy.proxy_server:app",
@@ -275,8 +275,8 @@ class ProxyInitializationHelpers:
         elif litellm.json_logs:
             # Use JSON log config for uvicorn to ensure all logs (including exceptions) are JSON
             uvicorn_args["log_config"] = _get_uvicorn_json_log_config()
-        elif os.environ.get("LITELLM_LOG"):
-            uvicorn_args["log_level"] = numeric_level
+        elif litellm_log := os.environ.get("LITELLM_LOG"):
+            uvicorn_args["log_level"] = resolve_log_level(litellm_log)
         if keepalive_timeout is not None:
             uvicorn_args["timeout_keep_alive"] = keepalive_timeout
         if timeout_worker_healthcheck is not None:

tests/test_litellm/proxy/test_proxy_cli.py

@@ -143,24 +143,20 @@ class TestProxyInitializationHelpers:
     def _uvicorn_access_info_enabled(args: dict) -> bool:
         import logging
 
-        names = ("uvicorn", "uvicorn.error", "uvicorn.access", "uvicorn.asgi")
-        saved = tuple((logging.getLogger(n), logging.getLogger(n).handlers[:], logging.getLogger(n).level) for n in names)
+        loggers = tuple(logging.getLogger(n) for n in ("uvicorn", "uvicorn.error", "uvicorn.access", "uvicorn.asgi"))
+        saved = tuple((lg, lg.handlers[:], lg.level, lg.propagate) for lg in loggers)
         try:
             uvicorn.Config(**args).configure_logging()
             return logging.getLogger("uvicorn.access").isEnabledFor(logging.INFO)
         finally:
-            for lg, handlers, level in saved:
+            for lg, handlers, level, propagate in saved:
                 lg.handlers[:] = handlers
                 lg.setLevel(level)
+                lg.propagate = propagate
 
     def test_litellm_log_error_silences_uvicorn_info_lines(self, monkeypatch):
-        import logging
-
         monkeypatch.setenv("LITELLM_LOG", "ERROR")
-        with patch(  # test-quality-ok: numeric_level is resolved from LITELLM_LOG once at import; no other way to set it
-            "litellm._logging.numeric_level", logging.ERROR
-        ):
-            args = ProxyInitializationHelpers._get_default_unvicorn_init_args("localhost", 8000)
+        args = ProxyInitializationHelpers._get_default_unvicorn_init_args("localhost", 8000)
 
         assert "log_config" not in args
         assert self._uvicorn_access_info_enabled(args) is False