diff --git a/litellm/__init__.py b/litellm/__init__.py index 651997321a3..5e8f4246cef 100644 --- a/litellm/__init__.py +++ b/litellm/__init__.py @@ -39,6 +39,7 @@ from litellm._logging import ( turn_on_json, log_level, ) +from litellm._logging import suppress_startup_output as suppress_startup_output import re from litellm.constants import ( DEFAULT_BATCH_SIZE, diff --git a/litellm/_logging.py b/litellm/_logging.py index 8974f85f517..5279cb233b4 100644 --- a/litellm/_logging.py +++ b/litellm/_logging.py @@ -10,10 +10,12 @@ import sys from collections.abc import Iterator, Mapping from datetime import datetime from logging import Formatter +from types import FrameType from typing import Final, TextIO from urllib.parse import unquote from pydantic import TypeAdapter +from typing_extensions import ReadOnly, TypedDict import litellm from litellm.constants import ( @@ -598,6 +600,7 @@ _LOG_FORMAT_PREFIX: Final = "%(asctime)s - %(name)s:%(levelname)s" _LOG_FORMAT_SUFFIX: Final = ": %(filename)s:%(lineno)s - %(message)s" _PLAIN_LOG_FORMAT: Final = _LOG_FORMAT_PREFIX + _LOG_FORMAT_SUFFIX _COLOR_LOG_FORMAT: Final = f"\033[92m{_LOG_FORMAT_PREFIX}\033[0m{_LOG_FORMAT_SUFFIX}" +_ANSI_ESCAPE: Final = re.compile(r"\x1b\[[0-9;]*m") def _stream_is_tty(stream: TextIO | None) -> bool: @@ -612,15 +615,28 @@ def _stream_is_tty(stream: TextIO | None) -> bool: return False -def _plain_log_format(stdout: TextIO | None, stderr: TextIO | None) -> str: - """The plain-text log format, colorized only when both streams are an interactive terminal. +def _color_enabled(stream: TextIO | None) -> bool: + """True when ANSI colors written to the stream reach an interactive terminal. Honors the NO_COLOR convention from no-color.org: color is disabled when NO_COLOR is present with a non-empty value. """ - if os.environ.get("NO_COLOR"): - return _PLAIN_LOG_FORMAT - return _COLOR_LOG_FORMAT if _stream_is_tty(stdout) and _stream_is_tty(stderr) else _PLAIN_LOG_FORMAT + return not os.environ.get("NO_COLOR") and _stream_is_tty(stream) + + +def _terminal_colors(stdout: TextIO | None, stderr: TextIO | None) -> bool: + """True when both streams are an interactive color terminal, the one rule for log lines and startup prints.""" + return _color_enabled(stdout) and _color_enabled(stderr) + + +def terminal_text(message: str) -> str: + """The message with its ANSI colors kept only on a color terminal, by the rule the plain log format uses.""" + return message if _terminal_colors(sys.stdout, sys.stderr) else _ANSI_ESCAPE.sub("", message) + + +def _plain_log_format(stdout: TextIO | None, stderr: TextIO | None) -> str: + """The plain-text log format, colorized only when both streams are an interactive terminal.""" + return _COLOR_LOG_FORMAT if _terminal_colors(stdout, stderr) else _PLAIN_LOG_FORMAT class LevelRoutingStreamHandler(logging.StreamHandler): @@ -642,8 +658,8 @@ class LevelRoutingStreamHandler(logging.StreamHandler): super().emit(record) -def _parse_json_logs_env(value: str | None) -> bool: - """Strict opt-in parse for the JSON_LOGS env var: only "true" (any case) enables JSON logs. +def _parse_env_flag(value: str | None) -> bool: + """Strict opt-in parse for a boolean env var such as JSON_LOGS: only "true" (any case) enables it. Matches the reader in litellm-proxy-extras/_logging.py. The previous bool(os.getenv(...)) treated any non-empty value, including "false" and "0", @@ -656,7 +672,18 @@ 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")) +json_logs: Final = _parse_env_flag(os.getenv("JSON_LOGS")) +suppress_startup_output: Final = _parse_env_flag(os.getenv("LITELLM_SUPPRESS_STARTUP_OUTPUT")) + + +class StartupOutputSettings(TypedDict, total=False): + json_logs: ReadOnly[object] + suppress_startup_output: ReadOnly[object] + + +STARTUP_OUTPUT_SETTINGS: Final = TypeAdapter(StartupOutputSettings) + + # 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] = resolve_log_level(log_level) @@ -743,7 +770,7 @@ class JsonFormatter(Formatter): return dt.isoformat() def format(self, record): - message_str: Final = record.getMessage() + message_str: Final = _ANSI_ESCAPE.sub("", record.getMessage()) json_record: Final[dict[str, object]] = { "message": message_str, "level": record.levelname, @@ -799,12 +826,14 @@ class CorrelationPlainFormatter(logging.Formatter): """Appends trace_id/session_id to plain-text log lines stamped by CorrelationContextFilter. Mirrors JsonFormatter's handling of these two fields so request_correlation_in_logs - behaves the same whether or not json_logs is enabled. + behaves the same whether or not json_logs is enabled. Unless it was built with the color format, + it also drops the ANSI color codes a message carries, which a piped log would store as text. """ def format(self, record: logging.LogRecord) -> str: rendered: Final = super().format(record) - formatted: Final = rendered if _is_redacted(record) else redact_string(rendered) + uncolored: Final = rendered if self._fmt == _COLOR_LOG_FORMAT else _ANSI_ESCAPE.sub("", rendered) + formatted: Final = uncolored if _is_redacted(record) else redact_string(uncolored) trace_id: Final = getattr(record, "trace_id", None) session_id: Final = getattr(record, "session_id", None) if not trace_id and not session_id: @@ -898,29 +927,46 @@ verbose_proxy_logger.addFilter(_diagnostic_filter) verbose_proxy_stdout_logger.addFilter(_diagnostic_filter) verbose_logger.addFilter(_diagnostic_filter) -_ANSI_ESCAPE: Final = re.compile(r"\x1b\[[0-9;]*m") - def print_startup_message(message: str) -> None: """Write a boot-time message meant for the operator's terminal. - Plain mode prints it unchanged, colors and spacing included. With JSON logs on, every line of - stdout is read by a log pipeline, so the message goes out as one INFO record of the proxy logger - instead, on stdout like the print whatever handlers the logging config gave that logger, with the - ANSI color codes and surrounding blank lines removed, located at the caller and emitted at any log - level, whole and unredacted as the print showed it; a blank spacer produces no record. + LITELLM_SUPPRESS_STARTUP_OUTPUT or litellm_settings.suppress_startup_output turns every one of them + off; a warning goes through print_startup_warning instead. Plain mode prints it with its spacing, + keeping the ANSI colors only on a color terminal by the same check as the plain log format, so a + container log never stores escape codes. + With JSON logs on, every line of stdout is read by a log pipeline, so the message goes out as one + INFO record of the proxy logger instead, on stdout like the print whatever handlers the logging + config gave that logger, with the ANSI color codes and surrounding blank lines removed, located at + the caller and emitted at any log level, whole and unredacted as the print showed it; a blank + spacer produces no record. """ + if litellm.suppress_startup_output is True: + return + frame: Final = inspect.currentframe() + _write_startup_message(message, frame.f_back if frame is not None else None, logging.INFO) + + +def print_startup_warning(message: str) -> None: + """Write a boot-time warning as print_startup_message writes a message, even with suppress_startup_output + on, since it names something the operator has to fix. With JSON logs on it is a WARNING record, on + stdout where the print put it, so a collector that filters on the level field keeps it.""" + frame: Final = inspect.currentframe() + _write_startup_message(message, frame.f_back if frame is not None else None, logging.WARNING) + + +def _write_startup_message(message: str, caller: FrameType | None, level: int) -> None: if not litellm.json_logs: - print(message) # noqa: T201 # plain mode: this is the operator-terminal print it replaces + import click + + click.echo(terminal_text(message)) return text: Final = _ANSI_ESCAPE.sub("", message).strip("\n") if not text: return - frame: Final = inspect.currentframe() - caller: Final = frame.f_back if frame is not None else None record: Final = verbose_proxy_logger.makeRecord( verbose_proxy_logger.name, - logging.INFO, + level, caller.f_code.co_filename if caller is not None else __file__, caller.f_lineno if caller is not None else 0, text, @@ -934,8 +980,8 @@ def print_startup_message(message: str) -> None: def _startup_json_handler() -> logging.Handler: - """The proxy's JSON handler on stdout, filters included, for one startup message.""" - handler: Final = LevelRoutingStreamHandler() + """The proxy's JSON handler on stdout, filters included, for one startup message or warning.""" + handler: Final = logging.StreamHandler(sys.stdout) handler.setFormatter(JsonFormatter()) handler.addFilter(_secret_filter) handler.addFilter(_correlation_filter) diff --git a/litellm/integrations/prometheus.py b/litellm/integrations/prometheus.py index bc8344fa686..d15956c0e95 100644 --- a/litellm/integrations/prometheus.py +++ b/litellm/integrations/prometheus.py @@ -1173,8 +1173,8 @@ class PrometheusLogger(CustomLogger): # Build label filters from valid configurations label_filters: Final = self._build_label_filters(parsed_configs) - # Pretty print the processed configuration - self._pretty_print_prometheus_config(label_filters) + if litellm.suppress_startup_output is not True: + self._pretty_print_prometheus_config(label_filters) return label_filters def _parse_exclude_config(self) -> tuple[frozenset[str], frozenset[str]]: diff --git a/litellm/proxy/db/check_migration.py b/litellm/proxy/db/check_migration.py index 83cc4501466..d126f112f90 100644 --- a/litellm/proxy/db/check_migration.py +++ b/litellm/proxy/db/check_migration.py @@ -4,7 +4,7 @@ import os import subprocess from typing import Final -from litellm._logging import print_startup_message, verbose_logger +from litellm._logging import print_startup_message, print_startup_warning, verbose_logger def extract_sql_commands(diff_output: str) -> list[str]: @@ -63,7 +63,7 @@ def check_prisma_schema_diff_helper(db_url: str) -> tuple[bool, list[str]]: run_prisma, ) except ImportError as e: - print_startup_message( + print_startup_warning( f"Skipping the migration diff: litellm-proxy-extras has no Prisma runner. Error: {e}", ) return False, [] @@ -96,14 +96,14 @@ def check_prisma_schema_diff_helper(db_url: str) -> tuple[bool, list[str]]: else: return False, [] except subprocess.TimeoutExpired: - print_startup_message( + print_startup_warning( f"Timed out after {timeout}s generating the migration diff. " f"Raise {PRISMA_COMMAND_TIMEOUT_ENV_VAR} if this database needs longer.", ) return False, [] except subprocess.CalledProcessError as e: error_message: Final = f"Failed to generate migration diff. Error: {e.stderr}" - print_startup_message(error_message) + print_startup_warning(error_message) return False, [] diff --git a/litellm/proxy/policy_engine/init_policies.py b/litellm/proxy/policy_engine/init_policies.py index 59d15b0ba0a..2d0e9d25368 100644 --- a/litellm/proxy/policy_engine/init_policies.py +++ b/litellm/proxy/policy_engine/init_policies.py @@ -11,7 +11,7 @@ from collections.abc import Mapping, Sequence from itertools import chain from typing import TYPE_CHECKING, Any, Final, Optional -from litellm._logging import print_startup_message, verbose_proxy_logger +from litellm._logging import print_startup_message, print_startup_warning, verbose_proxy_logger from litellm.proxy.policy_engine.attachment_registry import get_attachment_registry from litellm.proxy.policy_engine.policy_registry import get_policy_registry from litellm.proxy.policy_engine.policy_validator import PolicyValidator @@ -93,7 +93,7 @@ def _print_policies_on_startup( ) else: print_startup_message("\n".join((header, *policy_lines))) - print_startup_message( + print_startup_warning( f"\n{_yellow_color_code}Warning: No policy_attachments configured. Policies will not be applied to any requests.{_reset_color_code}\n", ) sys.stdout.flush() diff --git a/litellm/proxy/proxy_cli.py b/litellm/proxy/proxy_cli.py index 909f6de40cd..0d8ab98a0b1 100644 --- a/litellm/proxy/proxy_cli.py +++ b/litellm/proxy/proxy_cli.py @@ -10,16 +10,17 @@ import sys import urllib.parse as urlparse from collections.abc import Callable, Iterable, Mapping, Sequence from pathlib import Path -from typing import TYPE_CHECKING, Any, Final +from typing import TYPE_CHECKING, Annotated, Any, Final import click import httpx from click.core import ParameterSource from dotenv import load_dotenv -from pydantic import ConfigDict +from pydantic import BeforeValidator, ConfigDict, TypeAdapter +from typing_extensions import ReadOnly, TypedDict import litellm -from litellm._logging import print_startup_message +from litellm._logging import StartupOutputSettings, print_startup_message, print_startup_warning, terminal_text from litellm.constants import DEFAULT_NUM_WORKERS_LITELLM_PROXY from litellm.proxy.db.pgbouncer import ( PgBouncerError, @@ -205,7 +206,7 @@ def deprecated_v2_flag_passed_on_cli() -> bool: def _print_enforce_prisma_migration_check_notice() -> None: - print_startup_message( + print_startup_warning( "\033[1;33mLiteLLM Proxy: --enforce_prisma_migration_check is " "deprecated and has no effect, because the proxy always exits " "when database setup fails at startup. You can safely remove it.\033[0m", @@ -227,6 +228,36 @@ def _print_or_hold_enforce_prisma_migration_check_notice( return print_once +def _empty_as_none(value: object) -> object: + return value or None + + +class _ConfigStartupOutputSettings(TypedDict, total=False): + litellm_settings: ReadOnly[Annotated[StartupOutputSettings | None, BeforeValidator(_empty_as_none)]] + + +_CONFIG_STARTUP_OUTPUT_SETTINGS: Final = TypeAdapter(_ConfigStartupOutputSettings) + + +def _apply_config_suppress_startup_output(litellm_settings: StartupOutputSettings | None) -> None: + if litellm_settings is None or litellm_settings.get("suppress_startup_output") is not True: + return + litellm.suppress_startup_output = True + os.environ["LITELLM_SUPPRESS_STARTUP_OUTPUT"] = "true" + + +def _apply_config_logging_settings(litellm_settings: StartupOutputSettings | None) -> None: + """Turn on the config's json_logs and suppress_startup_output before any worker starts. Workers that + uvicorn or granian spawn import litellm afresh and read both from the env at import, so they log JSON + and stay quiet from their first line instead of from when load_config reaches the key.""" + _apply_config_suppress_startup_output(litellm_settings) + if litellm_settings is None or litellm_settings.get("json_logs") is not True: + return + litellm.json_logs = True + os.environ["JSON_LOGS"] = "true" + litellm.turn_on_json() + + class ProxyInitializationHelpers: @staticmethod def echo_litellm_version(): @@ -373,7 +404,7 @@ class ProxyInitializationHelpers: if "timeout_worker_healthcheck" in inspect.signature(uvicorn.Config.__init__).parameters: uvicorn_args["timeout_worker_healthcheck"] = timeout_worker_healthcheck else: - print_startup_message( + print_startup_warning( f"\033[1;33mLiteLLM Proxy: --timeout_worker_healthcheck " f"requires uvicorn>=0.37.0, but installed uvicorn=={uvicorn.__version__}. " f"Ignoring the flag.\033[0m", @@ -396,7 +427,7 @@ class ProxyInitializationHelpers: import uvicorn if max_requests_before_restart is None: - print_startup_message( + print_startup_warning( "\033[1;33mLiteLLM Proxy: --max_requests_before_restart_jitter " "has no effect without --max_requests_before_restart\033[0m\n", ) @@ -404,7 +435,7 @@ class ProxyInitializationHelpers: if "limit_max_requests_jitter" in inspect.signature(uvicorn.Config.__init__).parameters: uvicorn_args["limit_max_requests_jitter"] = jitter else: - print_startup_message( + print_startup_warning( f"\033[1;33mLiteLLM Proxy: --max_requests_before_restart_jitter " f"requires uvicorn>=0.41.0, but installed uvicorn=={uvicorn.__version__}. " f"Ignoring the flag.\033[0m", @@ -571,12 +602,12 @@ class ProxyInitializationHelpers: print_startup_message(f"\033[1;32mLiteLLM Proxy: Starting server on {host}:{port} using Granian\033[0m\n") if max_requests_before_restart is not None: - print_startup_message( + print_startup_warning( "\033[1;33mLiteLLM: --max_requests_before_restart is not supported by Granian " "(Granian uses workers_lifetime in seconds, not a per-request limit).\033[0m\n", ) if ciphers is not None: - print_startup_message("\033[1;33mLiteLLM: --ciphers is not applied when using --run_granian.\033[0m\n") + print_startup_warning("\033[1;33mLiteLLM: --ciphers is not applied when using --run_granian.\033[0m\n") kwargs: Final[dict[str, object]] = { "target": "litellm.proxy.proxy_server:app", @@ -698,7 +729,7 @@ class ProxyInitializationHelpers: gunicorn_options["max_requests"] = max_requests_before_restart if max_requests_before_restart_jitter is not None: if max_requests_before_restart is None: - print_startup_message( + print_startup_warning( "\033[1;33mLiteLLM Proxy: --max_requests_before_restart_jitter " "has no effect without --max_requests_before_restart\033[0m\n", ) @@ -739,7 +770,7 @@ class ProxyInitializationHelpers: with open(os.devnull, "w") as devnull: subprocess.Popen(command, stdout=devnull, stderr=devnull) except Exception as e: - print_startup_message(f""" + print_startup_warning(f""" LiteLLM Warning: proxy started with `ollama` model\n`ollama serve` failed with Exception{e}. \nEnsure you run `ollama serve` """) @@ -1325,6 +1356,19 @@ def run_server( os.environ[k] = v litellm_settings = None + env_config_file: Final = os.environ.get("CONFIG_FILE_PATH") + if ( + env_config_file + and os.environ.get("LITELLM_CONFIG_BUCKET_NAME") is None + and ProxyConfig().is_yaml(config_file_path=env_config_file) + ): + import asyncio + + _apply_config_suppress_startup_output( + _CONFIG_STARTUP_OUTPUT_SETTINGS.validate_python( + asyncio.run(ProxyConfig().read_config_file(config_file_path=env_config_file)) + ).get("litellm_settings") + ) if config is not None: """ Allow user to pass in db url via config @@ -1342,17 +1386,9 @@ def run_server( ### LITELLM SETTINGS ### litellm_settings = _config.get("litellm_settings", None) - if ( - litellm_settings is not None - and "json_logs" in litellm_settings - and litellm_settings["json_logs"] is True - ): - import litellm - - litellm.json_logs = True - os.environ["JSON_LOGS"] = "true" - - litellm.turn_on_json() + _apply_config_logging_settings( + _CONFIG_STARTUP_OUTPUT_SETTINGS.validate_python(_config).get("litellm_settings") + ) if held_prisma_notice is not None: held_prisma_notice() ### GENERAL SETTINGS ### @@ -1450,7 +1486,9 @@ def run_server( _bad_scheme = unsupported_db_scheme(_candidate_url) if _bad_scheme is not None: print( - f"\033[1;31mLiteLLM Proxy: {unsupported_db_scheme_message(_db_env, _bad_scheme)}\033[0m", + terminal_text( + f"\033[1;31mLiteLLM Proxy: {unsupported_db_scheme_message(_db_env, _bad_scheme)}\033[0m" + ), file=sys.stderr, flush=True, ) @@ -1553,7 +1591,7 @@ def run_server( env_value=os.getenv("USE_V2_MIGRATION_RESOLVER"), ) if deprecated_v2_flag_passed_on_cli() and use_v2_resolver: - print_startup_message( + print_startup_warning( "\033[1;33mLiteLLM Proxy: --use_v2_migration_resolver is " "deprecated and has no effect, because the v2 migration " "resolver is now the default. You can safely remove it. To " @@ -1561,7 +1599,7 @@ def run_server( "--use_legacy_migration_resolver.\033[0m", ) if not use_v2_resolver: - print_startup_message( + print_startup_warning( "\033[1;33mLiteLLM Proxy: Using the legacy (v1) migration " "resolver. It performs the diff-and-force recovery that can " "cause schema thrashing during rolling deploys where two " @@ -1583,22 +1621,26 @@ def run_server( # issues, and any `prisma db push` against a # partitioned LiteLLM_SpendLogs. print( - f"\033[1;31mLiteLLM Proxy: Database migration cannot proceed. {e}\033[0m", + terminal_text(f"\033[1;31mLiteLLM Proxy: Database migration cannot proceed. {e}\033[0m"), file=sys.stderr, flush=True, ) sys.exit(2) if not setup_ok: print( - "\033[1;31mLiteLLM Proxy: Database setup failed after multiple retries. " - "The proxy cannot start safely. Please check your database connection and migration status.\033[0m" + terminal_text( + "\033[1;31mLiteLLM Proxy: Database setup failed after multiple retries. " + "The proxy cannot start safely. Please check your database connection and migration status.\033[0m" + ) ) sys.exit(1) else: print( - "\033[1;31mLiteLLM Proxy: a database URL is set but the prisma CLI is neither on PATH nor importable " - "as a package, so the database cannot be set up. Install it with `pip install 'litellm[extra_proxy]'` " - "or run a shipped LiteLLM image.\033[0m" + terminal_text( + "\033[1;31mLiteLLM Proxy: a database URL is set but the prisma CLI is neither on PATH nor importable " + "as a package, so the database cannot be set up. Install it with `pip install 'litellm[extra_proxy]'` " + "or run a shipped LiteLLM image.\033[0m" + ) ) sys.exit(1) pgbouncer_settings: Final = PgBouncerSettings() @@ -1609,8 +1651,10 @@ def run_server( ) if isinstance(pooled_database_url, PgBouncerError): print( - f"\033[1;31mLiteLLM Proxy: LITELLM_PGBOUNCER_ENABLED is set but the in-container pgbouncer " - f"could not start: {pooled_database_url.reason}\033[0m", + terminal_text( + f"\033[1;31mLiteLLM Proxy: LITELLM_PGBOUNCER_ENABLED is set but the in-container pgbouncer " + f"could not start: {pooled_database_url.reason}\033[0m" + ), file=sys.stderr, flush=True, ) @@ -1675,7 +1719,7 @@ def run_server( run_gunicorn=run_gunicorn is True, ) if single_worker_warning is not None: - print_startup_message(f"\033[1;33m{single_worker_warning}\033[0m\n") + print_startup_warning(f"\033[1;33m{single_worker_warning}\033[0m\n") if run_gunicorn is False and run_hypercorn is False and run_granian is False: if limit_concurrency is not None: uvicorn_args["limit_concurrency"] = limit_concurrency diff --git a/litellm/proxy/proxy_server.py b/litellm/proxy/proxy_server.py index 5e37ff1ba65..5d034a72934 100644 --- a/litellm/proxy/proxy_server.py +++ b/litellm/proxy/proxy_server.py @@ -310,6 +310,7 @@ import litellm._redis from litellm import Router from litellm._internal_context import service_target, with_service_target from litellm._logging import ( + STARTUP_OUTPUT_SETTINGS, print_startup_message, redact_string, verbose_proxy_logger, @@ -5805,6 +5806,12 @@ class ProxyConfig: # verbose_proxy_logger.debug(f"loaded config={json.dumps(config, indent=4)}") return config + async def read_config_file(self, config_file_path: str) -> Mapping[str, object]: + """The config file with its includes merged, without the bucket, database and secret steps of get_config.""" + return await self._process_includes( + config=self._load_yaml_file(config_file_path), config_file_path=os.path.abspath(config_file_path) + ) + async def _process_includes(self, config: dict, config_file_path: str) -> dict: """ Process includes by appending their contents to the main config @@ -6429,13 +6436,8 @@ class ProxyConfig: search_tools_parsed: Final[list[SearchToolTypedDict]] = [] - print_startup_message("\033[32mLiteLLM: Proxy initialized with Search Tools:\033[0m") - for search_tool in search_tools_raw: - # Display loaded search tool search_tool_name = search_tool.get("search_tool_name", "") - search_provider = search_tool.get("litellm_params", {}).get("search_provider", "") - print_startup_message(f"\033[32m {search_tool_name} ({search_provider})\033[0m") # Handle os.environ/ variables in litellm_params litellm_params = search_tool.get("litellm_params", {}) @@ -6605,13 +6607,15 @@ class ProxyConfig: from litellm.types.integrations.prometheus import validate_caller_identity_settings validate_caller_identity_settings(litellm_settings) + if STARTUP_OUTPUT_SETTINGS.validate_python(litellm_settings).get("suppress_startup_output") is True: + litellm.suppress_startup_output = True # ANSI escape code for blue text blue_color_code: Final = "\033[94m" reset_color_code: Final = "\033[0m" for key, value in litellm_settings.items(): if key == "cache" and value is True: - print_startup_message(f"{blue_color_code}\nSetting Cache on Proxy{reset_color_code}") + print_startup_message(f"\n{blue_color_code}Setting Cache on Proxy{reset_color_code}") from litellm.caching.caching import Cache cache_params = {} @@ -6926,6 +6930,8 @@ class ProxyConfig: setattr(litellm, key, value) elif key == "drop_params": litellm.drop_params = drop_params_flag(value, "litellm_settings.drop_params", verbose_proxy_logger) + elif key == "suppress_startup_output": + continue else: verbose_proxy_logger.debug( "%s setting litellm.%s=%s%s", @@ -7281,6 +7287,13 @@ class ProxyConfig: ## SEARCH TOOLS SETTINGS search_tools: Final[list[SearchToolTypedDict] | None] = self.parse_search_tools(config) + if search_tools: + print_startup_message("\033[32mLiteLLM: Proxy initialized with Search Tools:\033[0m") + for tool in search_tools: + print_startup_message( + f"\033[32m {tool.get('search_tool_name', '')} " + f"({tool.get('litellm_params', {}).get('search_provider', '')})\033[0m" + ) ## SANDBOX TOOLS SETTINGS from litellm.sandbox.sandbox_tools import register_sandbox_tools @@ -9683,12 +9696,9 @@ async def initialize( master_key, \ user_custom_auth, \ prisma_client - from litellm.proxy.common_utils.banner import LITELLM_BANNER, show_banner + from litellm.proxy.common_utils.banner import LITELLM_BANNER - if litellm.json_logs: - print_startup_message(LITELLM_BANNER) - else: - show_banner() + print_startup_message(f"\n{LITELLM_BANNER}\n") if os.getenv("LITELLM_DONT_SHOW_FEEDBACK_BOX", "").lower() != "true": generate_feedback_box() user_model = model diff --git a/tests/integration/configuration/test_startup_output.py b/tests/integration/configuration/test_startup_output.py new file mode 100644 index 00000000000..fe9a5031778 --- /dev/null +++ b/tests/integration/configuration/test_startup_output.py @@ -0,0 +1,133 @@ +from __future__ import annotations + +import uuid +from collections.abc import Mapping +from pathlib import Path +from typing import Final + +import pytest +import yaml +from pydantic import JsonValue + +from tests.integration._support.client import Gateway, eventually +from tests.integration._support.process import owned_proxy_process + +STARTED_WORKER: Final = "Started server process" +RELOAD_LINE: Final = "search tool(s) into router" +RELOADS_PER_WORKER: Final = 3 +RELOAD_WAIT_SECONDS: Final = 60 +SEARCH_TOOLS_HEADER: Final = "Proxy initialized with Search Tools:" +STARTUP_MESSAGES: Final = ( + "██╗", + "Give Feedback / Get Help", + "Proxy initialized with Config, Set models:", + "Setting Cache on Proxy", + SEARCH_TOOLS_HEADER, + "Postgres connection budget", +) +ANSI_ESCAPE: Final = "\x1b[" +WORKER_COUNTS: Final = (1, 2) +CACHE_SETTINGS: Final[Mapping[str, JsonValue]] = {"cache": True, "cache_params": {"type": "redis"}} + + +def _lines_with(log: str, text: str) -> int: + return sum(text in line for line in log.splitlines()) + + +def _write_config( + directory: Path, upstream_url: str, model: str, search_tool: str, litellm_settings: Mapping[str, JsonValue] +) -> Path: + config: Final = directory / f"startup_output_{uuid.uuid4().hex}.yaml" + config.write_text( + yaml.safe_dump( + { + "model_list": [ + { + "model_name": model, + "litellm_params": { + "model": f"openai/{model}", + "api_base": f"{upstream_url}/v1", + "api_key": "integration-provider-key", + }, + } + ], + "search_tools": [ + { + "search_tool_name": search_tool, + "litellm_params": {"search_provider": "tavily", "api_key": "integration-search-key"}, + } + ], + "litellm_settings": dict(litellm_settings), + "general_settings": { + "master_key": "os.environ/LITELLM_MASTER_KEY", + "database_url": "os.environ/DATABASE_URL", + "proxy_config_reload_interval_seconds": 1, + }, + }, + sort_keys=False, + ) + ) + return config + + +def _boot_reload_and_stop( + gateway: Gateway, + directory: Path, + litellm_settings: Mapping[str, JsonValue], + overrides: Mapping[str, str], + workers: int, +) -> tuple[str, str]: + stamp: Final = uuid.uuid4().hex + model: Final = f"startup-output-{stamp}" + search_tool: Final = f"startup-output-search-{stamp}" + config: Final = _write_config(directory, gateway.upstream_url, model, search_tool, litellm_settings) + with owned_proxy_process( + gateway, + directory, + {"LITELLM_LOG": "INFO", **overrides}, + config=config, + workers=workers, + ) as owned: + reply: Final = owned.gateway.chat(model, text=f"startup output {stamp}") + assert reply["model"] == model, reply + reloads: Final = eventually( + lambda: _lines_with(owned.log.read_text(), RELOAD_LINE), + lambda count: count >= RELOADS_PER_WORKER * workers, + seconds=RELOAD_WAIT_SECONDS, + return_last_on_timeout=True, + ) + assert reloads >= RELOADS_PER_WORKER * workers, reloads + log: Final = owned.log + return log.read_text(), search_tool + + +@pytest.mark.parametrize("workers", WORKER_COUNTS) +def test_startup_messages_reach_a_piped_stdout_once_and_without_color_codes( + gateway: Gateway, tmp_path: Path, workers: int +) -> None: + log, search_tool = _boot_reload_and_stop(gateway, tmp_path, CACHE_SETTINGS, {}, workers) + + for message in STARTUP_MESSAGES: + assert message in log, (message, log) + assert _lines_with(log, SEARCH_TOOLS_HEADER) == workers, log + assert _lines_with(log, f"{search_tool} (tavily)") == workers, log + colored: Final = tuple(line for line in log.splitlines() if ANSI_ESCAPE in line) + assert colored == (), "lines with ANSI color codes on a piped stdout:\n" + "\n".join(colored) + + +@pytest.mark.parametrize( + ("litellm_settings", "overrides"), + [ + pytest.param(CACHE_SETTINGS, {"LITELLM_SUPPRESS_STARTUP_OUTPUT": "true"}, id="env-plain"), + pytest.param({**CACHE_SETTINGS, "json_logs": True, "suppress_startup_output": True}, {}, id="config-json"), + ], +) +def test_suppress_startup_output_leaves_out_every_startup_message( + gateway: Gateway, tmp_path: Path, litellm_settings: Mapping[str, JsonValue], overrides: Mapping[str, str] +) -> None: + workers: Final = 2 + log, search_tool = _boot_reload_and_stop(gateway, tmp_path, litellm_settings, overrides, workers) + + assert _lines_with(log, STARTED_WORKER) == workers, log + printed: Final = tuple(message for message in (*STARTUP_MESSAGES, search_tool) if message in log) + assert printed == (), (printed, log) diff --git a/tests/unit/enterprise/integrations/test_prometheus.py b/tests/unit/enterprise/integrations/test_prometheus.py index 987cfa03a5e..fc4a729ec98 100644 --- a/tests/unit/enterprise/integrations/test_prometheus.py +++ b/tests/unit/enterprise/integrations/test_prometheus.py @@ -217,6 +217,26 @@ def test_future_metrics_with_end_user_are_filtered(): litellm.enable_end_user_cost_tracking_prometheus_only = original_setting +@pytest.mark.parametrize("suppressed", [False, True]) +def test_prometheus_config_panel_obeys_suppress_startup_output( + monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str], suppressed: bool +): + """The processed-config panel is a startup print like the banner, so suppress_startup_output turns it off + while the label filters still load.""" + clear_prometheus_registry() + monkeypatch.setattr(litellm, "suppress_startup_output", suppressed) + monkeypatch.setattr( + litellm, + "prometheus_metrics_config", + [{"group": "service_metrics", "metrics": ["litellm_deployment_total_requests"], "include_labels": ["team"]}], + ) + + label_filters = PrometheusLogger()._parse_prometheus_config() + + assert label_filters["litellm_deployment_total_requests"] == ["team"] + assert ("Prometheus Configuration Processed" in capfd.readouterr().out) is not suppressed + + def test_prometheus_config_parsing(): """Test that prometheus metrics configuration is parsed correctly""" # Clear registry before test diff --git a/tests/unit/proxy/db/test_check_migration.py b/tests/unit/proxy/db/test_check_migration.py index b5685676941..3cc3d8c6713 100644 --- a/tests/unit/proxy/db/test_check_migration.py +++ b/tests/unit/proxy/db/test_check_migration.py @@ -81,7 +81,7 @@ def test_a_skipped_migration_diff_is_one_json_record_in_json_mode( monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] ) -> None: """ - With json_logs on, the notice that the migration diff was skipped is one INFO record on stdout, + With json_logs on, the notice that the migration diff was skipped is one WARNING record on stdout, also while the loggers sit at WARNING, as they do at boot without LITELLM_LOG. """ from litellm.proxy.db.check_migration import check_prisma_schema_diff_helper @@ -101,7 +101,7 @@ def test_a_skipped_migration_diff_is_one_json_record_in_json_mode( assert len(lines) == 1, lines record: Final = json.loads(lines[0]) assert (record["level"], record["message"]) == ( - "INFO", + "WARNING", "Skipping the migration diff: litellm-proxy-extras has no Prisma runner. " "Error: import of litellm_proxy_extras.prisma_toolchain halted; None in sys.modules", ) diff --git a/tests/unit/proxy/policy_engine/test_init_policies.py b/tests/unit/proxy/policy_engine/test_init_policies.py index b9b5f278252..ce0c48096d0 100644 --- a/tests/unit/proxy/policy_engine/test_init_policies.py +++ b/tests/unit/proxy/policy_engine/test_init_policies.py @@ -1,8 +1,10 @@ """The policy table printed at boot keeps its terminal form in plain mode and is JSON when json_logs is on.""" import json +import re import sys from collections.abc import Mapping, Sequence +from io import StringIO from typing import Final import pytest @@ -40,6 +42,15 @@ NO_ATTACHMENTS_WARNING: Final = ( ) +class _Stream(StringIO): + def __init__(self, terminal: bool) -> None: + super().__init__() + self._terminal = terminal + + def isatty(self) -> bool: + return self._terminal + + @pytest.mark.parametrize( ("attachments", "expected"), [ @@ -53,18 +64,24 @@ NO_ATTACHMENTS_WARNING: Final = ( ], ids=["with-attachments", "without-attachments"], ) +@pytest.mark.parametrize("terminal", [True, False], ids=["terminal", "piped"]) def test_policy_table_prints_unchanged_in_plain_mode( monkeypatch: pytest.MonkeyPatch, - capfd: pytest.CaptureFixture[str], attachments: Sequence[Mapping[str, object]] | None, expected: str, + terminal: bool, ) -> None: - """Operators without JSON logs keep the colored policy table byte for byte.""" + """Operators without JSON logs keep the colored policy table byte for byte on a terminal, and the same text + without color codes on a piped stdout.""" monkeypatch.setattr(litellm, "json_logs", False) + monkeypatch.delenv("NO_COLOR", raising=False) + stdout: Final = _Stream(terminal) + monkeypatch.setattr(sys, "stdout", stdout) + monkeypatch.setattr(sys, "stderr", _Stream(terminal)) _print_policies_on_startup(POLICIES, attachments) - assert capfd.readouterr() == (expected, "") + assert stdout.getvalue() == (expected if terminal else re.sub(r"\x1b\[\d+m", "", expected)) def test_policy_table_is_one_json_record_in_json_mode( @@ -98,8 +115,8 @@ def test_policy_table_is_one_json_record_in_json_mode( def test_missing_attachments_warning_is_a_second_json_record( monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] ) -> None: - """Without attachments the table and the yellow warning are two INFO records on stdout, where the two - prints put them.""" + """Without attachments the table and the yellow warning are an INFO and a WARNING record on stdout, + where the two prints put them.""" monkeypatch.setattr(litellm, "json_logs", True) monkeypatch.setattr(sys, "excepthook", sys.excepthook) turn_on_json() @@ -113,4 +130,4 @@ def test_missing_attachments_warning_is_a_second_json_record( "\n".join(("LiteLLM Policy Engine: Loaded 1 policies", "", *POLICY_ROWS)), NO_ATTACHMENTS_WARNING, ] - assert {record["level"] for record in records} == {"INFO"} + assert [record["level"] for record in records] == ["INFO", "WARNING"] diff --git a/tests/unit/proxy/proxy_server/test_proxy_config.py b/tests/unit/proxy/proxy_server/test_proxy_config.py index e59dd19271c..20a4ca87d42 100644 --- a/tests/unit/proxy/proxy_server/test_proxy_config.py +++ b/tests/unit/proxy/proxy_server/test_proxy_config.py @@ -13,6 +13,7 @@ import json import logging import os import re +import sys from collections.abc import Awaitable, Callable, Mapping from contextlib import nullcontext from dataclasses import dataclass @@ -28,6 +29,7 @@ from prisma.errors import DataError from pydantic import JsonValue, TypeAdapter, ValidationError import litellm +from litellm._logging import turn_on_json from litellm.proxy._types import CommonProxyErrors, ConfigGeneralSettings from litellm.proxy.common_utils.encrypt_decrypt_utils import encrypt_value_helper from litellm.types.router import Deployment, LiteLLM_Params @@ -2088,6 +2090,118 @@ def test_ProxyConfig_parse_search_tools_missing_returns_none(): assert pc.parse_search_tools({}) is None +@pytest.mark.asyncio +async def test_ProxyConfig_lists_search_tools_once_at_startup_not_on_every_reparse( + tmp_path: Path, monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] +): + """The search tools reload job and add_deployment re-parse search_tools every config reload interval, so + the startup listing belongs to load_config alone, or a container log repeats it every 30 seconds.""" + config_file: Final = tmp_path / "search.yaml" + config_file.write_text( + "model_list: []\n" + "search_tools:\n" + " - search_tool_name: web-search\n" + " litellm_params:\n" + " search_provider: tavily\n" + ) + monkeypatch.setattr(litellm, "json_logs", False) + monkeypatch.setattr(litellm, "suppress_startup_output", False) + monkeypatch.setattr("litellm.proxy.proxy_server.prisma_client", None) + monkeypatch.setattr("litellm.proxy.proxy_server.store_model_in_db", False) + monkeypatch.delenv("LITELLM_CONFIG_BUCKET_NAME", raising=False) + proxy_config: Final = ProxyConfig() + + await proxy_config.load_config(router=None, config_file_path=str(config_file)) + for _ in range(3): + assert proxy_config.parse_search_tools(proxy_config.get_config_state()) is not None + + out: Final = capfd.readouterr().out + assert out.count("Proxy initialized with Search Tools:") == 1, out + assert out.count("web-search (tavily)") == 1, out + + +@pytest.mark.asyncio +async def test_ProxyConfig_lists_each_search_tool_as_its_own_json_record( + tmp_path: Path, monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] +): + """With json_logs on, the startup listing is a header record and one record per tool, so a pipeline that + reads one tool per record keeps working.""" + config_file: Final = tmp_path / "search.yaml" + config_file.write_text( + "model_list: []\n" + "search_tools:\n" + " - search_tool_name: web-search\n" + " litellm_params:\n" + " search_provider: tavily\n" + " - search_tool_name: news-search\n" + " litellm_params:\n" + " search_provider: exa_ai\n" + ) + monkeypatch.setattr(litellm, "json_logs", True) + monkeypatch.setattr(litellm, "suppress_startup_output", False) + monkeypatch.setattr(sys, "excepthook", sys.excepthook) + monkeypatch.setattr("litellm.proxy.proxy_server.prisma_client", None) + monkeypatch.setattr("litellm.proxy.proxy_server.store_model_in_db", False) + monkeypatch.delenv("LITELLM_CONFIG_BUCKET_NAME", raising=False) + turn_on_json() + + await ProxyConfig().load_config(router=None, config_file_path=str(config_file)) + + messages: Final = [json.loads(raw)["message"] for raw in capfd.readouterr().out.splitlines() if raw.strip()] + listing: Final = [message for message in messages if "Search Tools" in message or "-search (" in message] + assert listing == [ + "LiteLLM: Proxy initialized with Search Tools:", + " web-search (tavily)", + " news-search (exa_ai)", + ], messages + +@pytest.mark.asyncio +@pytest.mark.parametrize( + ("already_on", "config_value"), + [ + pytest.param(True, False, id="env-var-on-and-config-false"), + pytest.param(False, True, id="config-key-below-cache"), + ], +) +async def test_ProxyConfig_load_config_keeps_startup_output_off_once_either_setting_turns_it_on( + tmp_path: Path, + monkeypatch: pytest.MonkeyPatch, + capfd: pytest.CaptureFixture[str], + already_on: bool, + config_value: bool, +): + """Only `true` turns suppress_startup_output on, from the env var or the config key, and a config `false` + never turns the env var back off. The key applies before any other litellm_settings key, so a `cache: true` + above it prints nothing either.""" + config_file: Final = tmp_path / "suppress.yaml" + config_file.write_text( + "model_list: []\n" + "litellm_settings:\n" + " cache: true\n" + " cache_params:\n" + " type: local\n" + f" suppress_startup_output: {str(config_value).lower()}\n" + "search_tools:\n" + " - search_tool_name: web-search\n" + " litellm_params:\n" + " search_provider: tavily\n" + ) + monkeypatch.setattr(litellm, "json_logs", False) + monkeypatch.setattr(litellm, "suppress_startup_output", already_on) + monkeypatch.setattr(litellm, "cache", None) + monkeypatch.setattr("litellm.proxy.proxy_server.prisma_client", None) + monkeypatch.setattr("litellm.proxy.proxy_server.store_model_in_db", False) + monkeypatch.delenv("LITELLM_CONFIG_BUCKET_NAME", raising=False) + + await ProxyConfig().load_config(router=None, config_file_path=str(config_file)) + + out: Final = capfd.readouterr().out + assert litellm.suppress_startup_output is True + assert "Setting Cache on Proxy" not in out, out + assert "Proxy initialized with Search Tools:" not in out, out + + + def test_ProxyConfig_merge_config_and_db_search_tools_returns_superset(): config_tools = [ { diff --git a/tests/unit/proxy/test_max_budget_env_var.py b/tests/unit/proxy/test_max_budget_env_var.py index ec71f70fa8f..95074ed1edd 100644 --- a/tests/unit/proxy/test_max_budget_env_var.py +++ b/tests/unit/proxy/test_max_budget_env_var.py @@ -18,10 +18,7 @@ async def test_max_budget_string_converted_to_float(): string. initialize() should convert it to float so the comparison `litellm.max_budget > 0` doesn't raise TypeError. """ - with ( - patch("litellm.proxy.common_utils.banner.show_banner"), - patch("litellm.proxy.proxy_server.generate_feedback_box"), - ): + with patch("litellm.proxy.proxy_server.generate_feedback_box"): from litellm.proxy.proxy_server import initialize original = litellm.max_budget @@ -36,10 +33,7 @@ async def test_max_budget_string_converted_to_float(): @pytest.mark.asyncio async def test_max_budget_float_stays_float(): """max_budget as float should still work.""" - with ( - patch("litellm.proxy.common_utils.banner.show_banner"), - patch("litellm.proxy.proxy_server.generate_feedback_box"), - ): + with patch("litellm.proxy.proxy_server.generate_feedback_box"): from litellm.proxy.proxy_server import initialize original = litellm.max_budget diff --git a/tests/unit/proxy/test_proxy_cli.py b/tests/unit/proxy/test_proxy_cli.py index d77731aa83b..afefae0dbb1 100644 --- a/tests/unit/proxy/test_proxy_cli.py +++ b/tests/unit/proxy/test_proxy_cli.py @@ -215,6 +215,23 @@ class TestProxyInitializationHelpers: ) assert args["timeout_worker_healthcheck"] == 30 + def test_an_old_uvicorn_drops_worker_healthcheck_and_warns_with_startup_output_suppressed( + self, monkeypatch: pytest.MonkeyPatch, capsys: pytest.CaptureFixture[str] + ) -> None: + class _UvicornConfigWithoutWorkerHealthcheck: + def __init__(self, app=None): + pass + + monkeypatch.setattr(litellm, "suppress_startup_output", True) + monkeypatch.setattr(litellm, "json_logs", False) + with patch("uvicorn.Config", _UvicornConfigWithoutWorkerHealthcheck): + args: Final = ProxyInitializationHelpers._get_default_unvicorn_init_args( + "localhost", 8000, timeout_worker_healthcheck=15 + ) + + assert "timeout_worker_healthcheck" not in args + assert "--timeout_worker_healthcheck requires uvicorn>=0.37.0" in capsys.readouterr().out + def test_get_reload_options_no_config_still_watches_env(self): opts = ProxyInitializationHelpers._get_reload_options(None) assert opts["reload"] is True @@ -1835,10 +1852,9 @@ class TestProxyInitializationHelpers: assert "uvicorn exits" not in warning @patch("uvicorn.run") - @patch("builtins.print") @patch("litellm.proxy.db.prisma_client.PrismaManager.setup_database") def test_single_worker_max_requests_warning_printed_on_uvicorn( - self, mock_setup_db, mock_print, mock_uvicorn_run + self, mock_setup_db, mock_uvicorn_run ): """uvicorn single-worker startup prints the does-not-recycle warning""" from click.testing import CliRunner @@ -1881,11 +1897,8 @@ class TestProxyInitializationHelpers: assert ( result.exit_code == 0 ), f"exit_code={result.exit_code}, output={result.output}" - assert any( - "--max_requests_before_restart 123 with --num_workers 1" in str(c) - and "uvicorn exits the process" in str(c) - for c in mock_print.call_args_list - ) + assert "--max_requests_before_restart 123 with --num_workers 1" in result.output + assert "uvicorn exits the process" in result.output @patch("litellm.proxy.proxy_cli.start_query_engine_reaper") @patch("uvicorn.run") @@ -1942,10 +1955,9 @@ class TestProxyInitializationHelpers: @patch("litellm.proxy.proxy_cli.ProxyInitializationHelpers.run_gunicorn_server") @patch("uvicorn.run") - @patch("builtins.print") @patch("litellm.proxy.db.prisma_client.PrismaManager.setup_database") def test_single_worker_max_requests_warning_printed_on_gunicorn( - self, mock_setup_db, mock_print, mock_uvicorn_run, mock_run_gunicorn + self, mock_setup_db, mock_uvicorn_run, mock_run_gunicorn ): """--run_gunicorn single-worker startup prints the gunicorn warning variant""" from click.testing import CliRunner @@ -1989,11 +2001,8 @@ class TestProxyInitializationHelpers: assert ( result.exit_code == 0 ), f"exit_code={result.exit_code}, output={result.output}" - assert any( - "--max_requests_before_restart 123 with --num_workers 1" in str(c) - and "gunicorn accepts no connections" in str(c) - for c in mock_print.call_args_list - ) + assert "--max_requests_before_restart 123 with --num_workers 1" in result.output + assert "gunicorn accepts no connections" in result.output @patch("litellm.proxy.proxy_cli.ProxyInitializationHelpers.init_hypercorn_server") @patch("uvicorn.run") @@ -2149,7 +2158,7 @@ class TestProxyInitializationHelpers: assert [call.args for call in reserved_before_run] == [("the gunicorn master",)] @pytest.mark.skipif(os.name == "nt", reason="gunicorn server path skips Windows") - def test_gunicorn_jitter_without_base_warns(self): + def test_gunicorn_jitter_without_base_warns(self, capsys: pytest.CaptureFixture[str]): """gunicorn path warns when jitter is set without --max_requests_before_restart""" pytest.importorskip("gunicorn") @@ -2160,7 +2169,6 @@ class TestProxyInitializationHelpers: with ( patch("gunicorn.app.base.BaseApplication.run", capture_run), - patch("builtins.print") as mock_print, patch( # test-quality-ok: option tests must not start a thread or change the pytest worker's child ownership "litellm.proxy.proxy_cli.start_query_engine_reaper" ), @@ -2178,7 +2186,7 @@ class TestProxyInitializationHelpers: assert "max_requests" not in captured["options"] assert "max_requests_jitter" not in captured["options"] - assert any("has no effect" in str(c) for c in mock_print.call_args_list) + assert "has no effect" in capsys.readouterr().out def test_apply_uvicorn_jitter_sets_arg_when_supported(self): class _NewUvicornConfig: @@ -2194,16 +2202,13 @@ class TestProxyInitializationHelpers: ) assert uvicorn_args["limit_max_requests_jitter"] == 50 - def test_apply_uvicorn_jitter_skipped_on_old_uvicorn(self): + def test_apply_uvicorn_jitter_skipped_on_old_uvicorn(self, capsys: pytest.CaptureFixture[str]): class _FakeUvicornConfig: def __init__(self, limit_max_requests=None): pass uvicorn_args: dict = {} - with ( - patch("uvicorn.Config", _FakeUvicornConfig), - patch("builtins.print") as mock_print, - ): + with patch("uvicorn.Config", _FakeUvicornConfig): ProxyInitializationHelpers._apply_uvicorn_max_requests_jitter( uvicorn_args=uvicorn_args, max_requests_before_restart=1000, @@ -2211,19 +2216,18 @@ class TestProxyInitializationHelpers: ) assert "limit_max_requests_jitter" not in uvicorn_args - assert any("0.41.0" in str(c) for c in mock_print.call_args_list) + assert "0.41.0" in capsys.readouterr().out - def test_apply_uvicorn_jitter_without_base_warns(self): + def test_apply_uvicorn_jitter_without_base_warns(self, capsys: pytest.CaptureFixture[str]): uvicorn_args: dict = {} - with patch("builtins.print") as mock_print: - ProxyInitializationHelpers._apply_uvicorn_max_requests_jitter( - uvicorn_args=uvicorn_args, - max_requests_before_restart=None, - jitter=50, - ) + ProxyInitializationHelpers._apply_uvicorn_max_requests_jitter( + uvicorn_args=uvicorn_args, + max_requests_before_restart=None, + jitter=50, + ) assert "limit_max_requests_jitter" not in uvicorn_args - assert any("has no effect" in str(c) for c in mock_print.call_args_list) + assert "has no effect" in capsys.readouterr().out @patch.dict(os.environ, {}, clear=True) def test_construct_database_url_from_env_vars(self): @@ -2648,10 +2652,56 @@ class TestRunServerDbSetup: assert exit_info.value.code == 1 assert "a database URL is set but the prisma CLI is neither on PATH nor importable" in out assert "pip install 'litellm[extra_proxy]'" in out + assert "\x1b[" not in out else: assert "prisma CLI" not in out assert "Setup complete" in out + @patch("atexit.register") + @patch("litellm.proxy.db.prisma_client.PrismaManager.setup_database", return_value=True) + @patch("litellm.proxy.db.prisma_client.PrismaManager.build_request_log_indexes", return_value=True) + def test_a_pgbouncer_that_cannot_start_stops_the_cli_with_an_uncolored_error_off_a_terminal( + self, + mock_build_indexes, + mock_setup_database, + mock_atexit_register, + tmp_path: Path, + capsys: pytest.CaptureFixture[str], + ) -> None: + from litellm.proxy.proxy_server import ProxyConfig + + mock_proxy_module: Final = MagicMock( + app=MagicMock(), + ProxyConfig=ProxyConfig, + KeyManagementSettings=MagicMock(), + save_worker_config=MagicMock(), + ) + clean_env: Final = { + k: v + for k, v in os.environ.items() + if not k.startswith(("DATABASE_URL", "DIRECT_URL", "LITELLM_PGBOUNCER_", "DISABLE_SCHEMA_UPDATE")) + } + pgbouncer_env: Final = { + "DATABASE_URL": "postgresql://test:test@localhost:5432/test", + "LITELLM_PGBOUNCER_ENABLED": "true", + "LITELLM_PGBOUNCER_BINARY": str(tmp_path / "missing-pgbouncer"), + } + + with ( + patch.dict(os.environ, {**clean_env, **pgbouncer_env}, clear=True), + patch.dict( + "sys.modules", + {"proxy_server": mock_proxy_module, "litellm.proxy.proxy_server": mock_proxy_module}, + ), + pytest.raises(SystemExit) as exit_info, + ): + run_server.main(["--local", "--skip_server_startup"], standalone_mode=False) + + error: Final = capsys.readouterr().err + assert exit_info.value.code == 1 + assert "LITELLM_PGBOUNCER_ENABLED is set but the in-container pgbouncer could not start" in error + assert "\x1b[" not in error + @patch("subprocess.run") @patch("atexit.register") @patch("litellm.proxy.db.prisma_client.PrismaManager.setup_database") @@ -2726,6 +2776,7 @@ class TestRunServerDbSetup: mock_setup_database, mock_atexit_register, mock_subprocess_run, + capsys, ): """A sqlite DATABASE_URL must exit immediately, before any prisma call, instead of stalling on a migration against the postgresql-only schema.""" @@ -2764,6 +2815,9 @@ class TestRunServerDbSetup: ) assert exc_info.value.code == 1 mock_setup_database.assert_not_called() + err: Final = capsys.readouterr().err + assert "sqlite" in err + assert "\x1b[" not in err @patch("subprocess.run") @patch("atexit.register") @@ -2825,6 +2879,51 @@ class TestRunServerDbSetup: mock_setup_database.assert_called_once_with(use_migrate=True, use_v2_resolver=True) assert "--use_v2_migration_resolver is deprecated" not in capsys.readouterr().out + @patch("subprocess.run", return_value=MagicMock(returncode=0)) + @patch("atexit.register") + @patch("litellm.proxy.db.prisma_client.PrismaManager.setup_database", return_value=True) + @patch("litellm.proxy.db.prisma_client.PrismaManager.build_request_log_indexes") + def test_the_deprecated_v2_resolver_flag_warns_with_startup_output_suppressed( + self, + mock_build_indexes, + mock_setup_database, + mock_atexit_register, + mock_subprocess_run, + monkeypatch: pytest.MonkeyPatch, + capsys: pytest.CaptureFixture[str], + ) -> None: + from litellm.proxy.proxy_server import ProxyConfig + + mock_proxy_module: Final = MagicMock( + app=MagicMock(), + ProxyConfig=ProxyConfig, + KeyManagementSettings=MagicMock(), + save_worker_config=MagicMock(), + ) + clean_env: Final = { + k: v + for k, v in os.environ.items() + if k not in ("DATABASE_URL", "DIRECT_URL", "USE_V2_MIGRATION_RESOLVER", "DISABLE_SCHEMA_UPDATE") + } + monkeypatch.setattr(litellm, "suppress_startup_output", True) + monkeypatch.setattr(litellm, "json_logs", False) + + with ( + patch.dict( + os.environ, {**clean_env, "DATABASE_URL": "postgresql://test:test@localhost:5432/test"}, clear=True + ), + patch.dict( + "sys.modules", + {"proxy_server": mock_proxy_module, "litellm.proxy.proxy_server": mock_proxy_module}, + ), + ): + run_server.main( + ["--local", "--skip_server_startup", "--use_v2_migration_resolver"], standalone_mode=False + ) + + mock_setup_database.assert_called_once_with(use_migrate=True, use_v2_resolver=True) + assert "--use_v2_migration_resolver is deprecated and has no effect" in capsys.readouterr().out + @pytest.mark.parametrize( ("arguments", "environment", "warned"), ( @@ -3968,11 +4067,104 @@ def _boot_from_config_file(config_path: Path, *flags: str) -> str | None: return os.environ.get("JSON_LOGS") +COUNTING_SECRET_MANAGER_MODULE: Final = """ +import os + +from litellm.integrations.custom_secret_manager import CustomSecretManager + + +class CountingSecretManager(CustomSecretManager): + def __init__(self): + super().__init__() + self._log("constructed") + + @staticmethod + def _log(event): + with open(os.environ["SECRET_READ_LOG"], "a") as f: + f.write(event + "\\n") + + def sync_read_secret(self, secret_name, optional_params=None, timeout=None, **kwargs): + self._log(secret_name) + return "from-secret-manager" + + async def async_read_secret(self, secret_name, optional_params=None, timeout=None, **kwargs): + self._log(secret_name) + return "from-secret-manager" +""" + +SECRET_MANAGER_BACKED_CONFIG: Final = """ +model_list: + - model_name: my-model + litellm_params: + model: openai/gpt-5.4-mini + api_key: os.environ/MY_PROVIDER_KEY + +litellm_settings: + suppress_startup_output: true + +general_settings: + key_management_system: custom + key_management_settings: + custom_secret_manager: counting_secret_manager.CountingSecretManager + hosted_keys: + - MY_PROVIDER_KEY +""" + + class TestJsonLogsConfigReachesSpawnedWorkers: """`litellm_settings.json_logs: true` turns JSON on inside the CLI process, but the workers that uvicorn or granian spawn are fresh interpreters that pick plain or JSON from the JSON_LOGS environment variable at import. The CLI has to export it, or every worker logs plain text until - its own load_config reaches the key.""" + its own load_config reaches the key. `suppress_startup_output` has the same problem with the banner + each worker prints before its load_config.""" + + @staticmethod + def _write_config(path: Path, litellm_settings: dict[str, object]) -> Path: + path.write_text(yaml.dump({"model_list": [], "litellm_settings": litellm_settings})) + return path + + @staticmethod + def _env_after_boot( + name: str, + config: Path | None = None, + config_file_path_env: Path | None = None, + extra_env: dict[str, str] | None = None, + proxy_config_class: object = None, + ) -> str | None: + from litellm.proxy.proxy_server import ProxyConfig + + mock_proxy_module: Final = MagicMock( + app=MagicMock(), + ProxyConfig=proxy_config_class or ProxyConfig, + KeyManagementSettings=MagicMock(), + save_worker_config=MagicMock(), + ) + clean_env: Final = { + k: v + for k, v in os.environ.items() + if k + not in ( + "DATABASE_URL", + "DIRECT_URL", + "JSON_LOGS", + "LITELLM_SUPPRESS_STARTUP_OUTPUT", + "CONFIG_FILE_PATH", + "LITELLM_CONFIG_BUCKET_NAME", + ) + } + config_env: Final = {} if config_file_path_env is None else {"CONFIG_FILE_PATH": str(config_file_path_env)} + config_args: Final = [] if config is None else ["--config", str(config)] + with ( + patch.dict(os.environ, {**clean_env, **config_env, **(extra_env or {})}, clear=True), + patch.dict( + "sys.modules", + {"proxy_server": mock_proxy_module, "litellm.proxy.proxy_server": mock_proxy_module}, + ), + patch("atexit.register"), + patch("litellm.turn_on_json"), # test-quality-ok: it swaps every logger handler in this pytest worker + ): + run_server.main([*config_args, "--local", "--skip_server_startup"], standalone_mode=False) + return os.environ.get(name) def test_json_logs_true_exports_json_logs_to_spawned_workers( self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch @@ -3991,11 +4183,126 @@ class TestJsonLogsConfigReachesSpawnedWorkers: assert _boot_from_config_file(config_path) is None + @pytest.mark.parametrize("litellm_settings", [[], "", 0, False]) + @pytest.mark.parametrize("via_config_file_path_env", [False, True]) + def test_an_empty_litellm_settings_still_boots( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch, litellm_settings: object, via_config_file_path_env: bool + ) -> None: + monkeypatch.setattr(litellm, "suppress_startup_output", False) + config_file: Final = tmp_path / "config.yaml" + config_file.write_text(yaml.dump({"model_list": [], "litellm_settings": litellm_settings})) + exported: Final = ( + self._env_after_boot("LITELLM_SUPPRESS_STARTUP_OUTPUT", config_file_path_env=config_file) + if via_config_file_path_env + else self._env_after_boot("LITELLM_SUPPRESS_STARTUP_OUTPUT", config=config_file) + ) + assert exported is None + + @pytest.mark.parametrize(("setting", "exported"), [(True, "true"), ("true", None), (False, None)]) + def test_only_a_boolean_suppress_startup_output_reaches_spawned_workers( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch, setting: object, exported: str | None + ) -> None: + monkeypatch.setattr(litellm, "suppress_startup_output", False) + config: Final = self._write_config(tmp_path / "config.yaml", {"suppress_startup_output": setting}) + assert self._env_after_boot("LITELLM_SUPPRESS_STARTUP_OUTPUT", config=config) == exported + + @pytest.mark.parametrize(("name", "exported"), [("LITELLM_SUPPRESS_STARTUP_OUTPUT", "true"), ("JSON_LOGS", None)]) + def test_a_config_named_by_CONFIG_FILE_PATH_passes_only_suppress_startup_output_to_spawned_workers( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch, name: str, exported: str | None + ) -> None: + """Its json_logs stays the workers' own to read, as before, so uvicorn's lines keep their plain format.""" + monkeypatch.setattr(litellm, "json_logs", False) + monkeypatch.setattr(litellm, "suppress_startup_output", False) + settings: Final[dict[str, object]] = {"json_logs": True, "suppress_startup_output": True} + config_file: Final = self._write_config(tmp_path / "config.yaml", settings) + assert self._env_after_boot(name, config_file_path_env=config_file) == exported + + def test_a_CONFIG_FILE_PATH_quiet_config_wins_over_a_cli_config_too( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch + ) -> None: + """Workers load CONFIG_FILE_PATH ahead of --config, so its key quiets the CLI when both are set.""" + monkeypatch.setattr(litellm, "suppress_startup_output", False) + cli_config: Final = self._write_config(tmp_path / "cli.yaml", {}) + env_config: Final = self._write_config(tmp_path / "env.yaml", {"suppress_startup_output": True}) + exported: Final = self._env_after_boot( + "LITELLM_SUPPRESS_STARTUP_OUTPUT", config=cli_config, config_file_path_env=env_config + ) + assert exported == "true" + + @pytest.mark.parametrize( + ("config_file", "env_file", "extra_env"), + [ + ("config.yaml", "missing.yaml", {}), + ("config.json", "config.json", {}), + ("config.yaml", "config.yaml", {"LITELLM_CONFIG_BUCKET_NAME": "litellm-configs"}), + ], + ids=["missing-file", "not-yaml", "bucket-config"], + ) + def test_a_CONFIG_FILE_PATH_workers_skip_is_skipped_by_the_cli_too( + self, + tmp_path: Path, + monkeypatch: pytest.MonkeyPatch, + config_file: str, + env_file: str, + extra_env: dict[str, str], + ) -> None: + """Workers load CONFIG_FILE_PATH only when it names a YAML file and no config bucket is set, and a boot + with any other value starts, so the CLI reads nothing from it either instead of failing the boot.""" + monkeypatch.setattr(litellm, "suppress_startup_output", False) + self._write_config(tmp_path / config_file, {"suppress_startup_output": True}) + exported: Final = self._env_after_boot( + "LITELLM_SUPPRESS_STARTUP_OUTPUT", config_file_path_env=tmp_path / env_file, extra_env=extra_env + ) + assert exported is None + + def test_a_CONFIG_FILE_PATH_boot_reads_no_secret_before_the_workers_do( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch + ) -> None: + """The CLI takes only the suppress key from CONFIG_FILE_PATH, so a config backed by a secret manager is + read from it once per worker, as before, not once more by the CLI.""" + from litellm.proxy.proxy_server import ProxyConfig + + monkeypatch.setattr(litellm, "suppress_startup_output", False) + monkeypatch.setattr(litellm, "secret_manager_client", None) + monkeypatch.setattr(litellm, "_key_management_system", None) + monkeypatch.setattr(litellm, "_key_management_settings", litellm._key_management_settings) + reads: Final = tmp_path / "secret_reads.log" + (tmp_path / "counting_secret_manager.py").write_text(COUNTING_SECRET_MANAGER_MODULE) + config_file: Final = tmp_path / "config.yaml" + config_file.write_text(SECRET_MANAGER_BACKED_CONFIG) + + exported: Final = self._env_after_boot( + "LITELLM_SUPPRESS_STARTUP_OUTPUT", + config_file_path_env=config_file, + extra_env={"SECRET_READ_LOG": str(reads)}, + proxy_config_class=ProxyConfig, + ) + + assert exported == "true" + assert not reads.exists(), reads.read_text() + + def test_a_CONFIG_FILE_PATH_key_set_in_an_included_file_reaches_spawned_workers( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch + ) -> None: + from litellm.proxy.proxy_server import ProxyConfig + + monkeypatch.setattr(litellm, "suppress_startup_output", False) + self._write_config(tmp_path / "quiet.yaml", {"suppress_startup_output": True}) + config_file: Final = tmp_path / "config.yaml" + config_file.write_text(yaml.dump({"include": ["quiet.yaml"], "model_list": []})) + + exported: Final = self._env_after_boot( + "LITELLM_SUPPRESS_STARTUP_OUTPUT", config_file_path_env=config_file, proxy_config_class=ProxyConfig + ) + + assert exported == "true" + class TestEnforcePrismaMigrationCheckNoticeAroundTheConfigRead: """With a config file, the `--enforce_prisma_migration_check` deprecation notice waits until the config - is read, so a `json_logs: true` set only there makes it a JSON record. It is printed once either way, - and a boot whose config read fails still prints it before the error, as it did before the wait.""" + is read, so a `json_logs: true` set only there makes it a JSON record, while `suppress_startup_output: true` + leaves it, since it is a warning. Otherwise it is printed once, and a boot whose config read fails still + prints it before the error, as it did before the wait.""" NOTICE: Final = "--enforce_prisma_migration_check is deprecated and has no effect" FLAG: Final = "--enforce_prisma_migration_check" @@ -4035,13 +4342,26 @@ class TestEnforcePrismaMigrationCheckNoticeAroundTheConfigRead: assert len(notice_lines) == 1, notice_lines assert self.NOTICE in json.loads(notice_lines[0])["message"] + @pytest.mark.parametrize("json_logs", [False, True]) + def test_a_config_only_suppress_startup_output_keeps_the_notice( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch, capsys: pytest.CaptureFixture[str], json_logs: bool + ) -> None: + monkeypatch.setattr(litellm, "json_logs", json_logs) + monkeypatch.setattr(litellm, "suppress_startup_output", False) + config_path: Final = tmp_path / "config.yaml" + config_path.write_text(yaml.dump({"model_list": [], "litellm_settings": {"suppress_startup_output": True}})) + + _boot_from_config_file(config_path, self.FLAG) + + assert capsys.readouterr().out.count(self.NOTICE) == 1 + def test_granian_flag_notices_are_json_records_in_json_mode( monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] ) -> None: """The yellow notices for the flags Granian ignores (`--max_requests_before_restart`, `--ciphers`) are - printed while the launcher starts; with json_logs on they are INFO records on stdout like every other - line, not plaintext between the records.""" + printed while the launcher starts; with json_logs on they are WARNING records on stdout after the INFO + start line, not plaintext between the records.""" pytest.importorskip("granian") monkeypatch.setattr(litellm, "json_logs", True) monkeypatch.setattr(sys, "excepthook", sys.excepthook) @@ -4072,4 +4392,4 @@ def test_granian_flag_notices_are_json_records_in_json_mode( "(Granian uses workers_lifetime in seconds, not a per-request limit).", "LiteLLM: --ciphers is not applied when using --run_granian.", ] - assert {record["level"] for record in records} == {"INFO"} + assert [record["level"] for record in records] == ["INFO", "WARNING", "WARNING"] diff --git a/tests/unit/proxy/test_proxy_server_endpoints_and_startup.py b/tests/unit/proxy/test_proxy_server_endpoints_and_startup.py index 55d1587669a..0c83d6c6c37 100644 --- a/tests/unit/proxy/test_proxy_server_endpoints_and_startup.py +++ b/tests/unit/proxy/test_proxy_server_endpoints_and_startup.py @@ -15615,8 +15615,8 @@ def test_feedback_box_is_one_json_record_in_json_mode( async def test_initialize_prints_the_banner_between_blank_lines_in_plain_mode( monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] ) -> None: - """Operators without JSON logs see the banner exactly as before, through show_banner()'s flushing - click.echo.""" + """Operators without JSON logs see the banner exactly as before, flushed at once as show_banner()'s + click.echo did.""" monkeypatch.setattr(litellm, "json_logs", False) monkeypatch.setenv("LITELLM_DONT_SHOW_FEEDBACK_BOX", "true") diff --git a/tests/unit/test_logging.py b/tests/unit/test_logging.py index 195d5afe000..fcd835e93dd 100644 --- a/tests/unit/test_logging.py +++ b/tests/unit/test_logging.py @@ -7,7 +7,7 @@ import logging import re import sys import time -from io import StringIO +from io import BytesIO, StringIO, TextIOWrapper from pathlib import Path from typing import Final, List @@ -31,10 +31,11 @@ from litellm._logging import ( StdoutLogTruncationFilter, _get_uvicorn_json_log_config, _initialize_loggers_with_handler, - _parse_json_logs_env, + _parse_env_flag, _plain_log_format, _stdout_truncation_marker, print_startup_message, + print_startup_warning, turn_on_json, format_base64_size, session_id_var, @@ -46,6 +47,7 @@ from litellm._logging import ( verbose_router_logger, ) from litellm.constants import LITELLM_TRUNCATED_PAYLOAD_FIELD +from litellm.proxy.common_utils.banner import LITELLM_BANNER from litellm.integrations.custom_logger import CustomLogger from litellm.litellm_core_utils import secret_redaction from litellm.types.utils import StandardLoggingPayload @@ -1402,6 +1404,32 @@ def test_plain_log_format_survives_hostile_streams(stdout, stderr): assert _plain_log_format(stdout, stderr) == _PLAIN_LOG_FORMAT +def _router_success_record() -> logging.LogRecord: + return logging.LogRecord( + "LiteLLM Router", logging.INFO, "router.py", 1, "litellm.acompletion(model=%s)\033[32m 200 OK\033[0m", ("gpt-5.6",), None + ) + + +@pytest.mark.parametrize( + ("log_format", "want_suffix"), + [ + (_COLOR_LOG_FORMAT, "litellm.acompletion(model=gpt-5.6)\033[32m 200 OK\033[0m"), + (_PLAIN_LOG_FORMAT, "router.py:1 - litellm.acompletion(model=gpt-5.6) 200 OK"), + ], +) +def test_plain_formatter_keeps_message_colors_only_with_the_color_format(log_format: str, want_suffix: str): + """A message that embeds color codes keeps them on a color terminal. Piped, or under NO_COLOR, the plain + format is chosen and the codes go too, so a container log never stores them as text.""" + assert CorrelationPlainFormatter(log_format).format(_router_success_record()).endswith(want_suffix) + + +def test_json_formatter_drops_color_codes_from_the_message(): + """A JSON log line is read by a log pipeline, never a terminal, so a colored message arrives as plain text.""" + assert json.loads(JsonFormatter().format(_router_success_record()))["message"] == ( + "litellm.acompletion(model=gpt-5.6) 200 OK" + ) + + def test_level_routing_handler_falls_back_to_stderr_when_stdout_is_unusable(monkeypatch, capsys): logger = logging.getLogger("test_level_routing_fallback") logger.handlers.clear() @@ -1436,9 +1464,9 @@ def test_level_routing_handler_falls_back_to_stderr_when_stdout_is_unusable(monk (None, False), ], ) -def test_parse_json_logs_env_enables_only_on_true(value, want): +def test_parse_env_flag_enables_only_on_true(value: str | None, want: bool): """JSON_LOGS=false / 0 must not enable JSON logs (LIT-5558).""" - assert _parse_json_logs_env(value) is want + assert _parse_env_flag(value) is want def test_plain_log_format_survives_none_streams(): @@ -1813,17 +1841,98 @@ def test_print_verbose_formats_args_only_when_set_verbose_is_on(monkeypatch, cap assert capsys.readouterr().out == "key k1 value cached-vector\n" -def test_print_startup_message_prints_plain_mode_text_unchanged( - monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] -) -> None: - """Operators without JSON logs keep the colored, spaced terminal output exactly as before.""" +class _CapturedStream(StringIO): + def __init__(self, tty: bool) -> None: + super().__init__() + self._tty = tty + + def isatty(self) -> bool: + return self._tty + + +@pytest.mark.parametrize( + "stdout_tty, stderr_tty, no_color, want_color", + [(True, True, None, True), (False, True, None, False), (True, False, None, False), (True, True, "1", False)], +) +def test_print_startup_message_keeps_colors_only_on_a_color_terminal( + monkeypatch: pytest.MonkeyPatch, stdout_tty: bool, stderr_tty: bool, no_color: str | None, want_color: bool +): + """Operators without JSON logs keep the colored, spaced output on a terminal. A container runtime reads + stdout through a pipe and stores the escape codes as text, so there, and under NO_COLOR, the colors go. + The rule is the plain log format's, so a `2>file` run drops the colors from prints and log lines alike.""" monkeypatch.setattr(litellm, "json_logs", False) + if no_color is None: + monkeypatch.delenv("NO_COLOR", raising=False) + else: + monkeypatch.setenv("NO_COLOR", no_color) + stdout: Final = _CapturedStream(stdout_tty) + monkeypatch.setattr(sys, "stdout", stdout) + monkeypatch.setattr(sys, "stderr", _CapturedStream(stderr_tty)) + assert (_plain_log_format(sys.stdout, sys.stderr) == _COLOR_LOG_FORMAT) is want_color print_startup_message("\n\033[1;32mLiteLLM: Proxy initialized with Config, Set models:\033[0m\n") + assert stdout.getvalue() == ( + "\n\033[1;32mLiteLLM: Proxy initialized with Config, Set models:\033[0m\n\n" + if want_color + else "\nLiteLLM: Proxy initialized with Config, Set models:\n\n" + ) + + +def test_print_startup_message_writes_the_banner_as_utf8_to_an_ascii_stdout(monkeypatch: pytest.MonkeyPatch): + monkeypatch.setattr(litellm, "json_logs", False) + monkeypatch.setattr(litellm, "suppress_startup_output", False) + raw: Final = BytesIO() + monkeypatch.setattr(sys, "stdout", TextIOWrapper(raw, encoding="ascii")) + + print_startup_message(f"\n{LITELLM_BANNER}\n") + + assert raw.getvalue().decode("utf-8") == f"\n{LITELLM_BANNER}\n\n" + + +@pytest.mark.parametrize("json_logs", [False, True]) +def test_print_startup_message_writes_nothing_when_suppressed( + monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str], json_logs: bool +): + """suppress_startup_output turns the startup messages off in plain and JSON mode alike, for operators + whose log pipeline wants only the logger's own lines.""" + monkeypatch.setattr(litellm, "json_logs", json_logs) + monkeypatch.setattr(litellm, "suppress_startup_output", True) + monkeypatch.setattr(sys, "excepthook", sys.excepthook) + if json_logs: + turn_on_json() + + print_startup_message("\033[32mLiteLLM: Proxy initialized with Search Tools:\033[0m\n\033[32m web-search (tavily)\033[0m") + + assert capfd.readouterr() == ("", "") + + +@pytest.mark.parametrize("json_logs", [False, True]) +def test_print_startup_warning_still_prints_when_suppressed( + monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str], json_logs: bool +): + """A warning names something the operator has to fix, like an ignored flag or a failed migration diff, + so suppress_startup_output leaves it in place. In JSON mode it is a WARNING record at the caller's + location, on stdout where the print put it, so a collector's WARNING filter keeps it.""" + monkeypatch.setattr(litellm, "json_logs", json_logs) + monkeypatch.setattr(litellm, "suppress_startup_output", True) + monkeypatch.setattr(sys, "excepthook", sys.excepthook) + if json_logs: + turn_on_json() + + print_startup_warning("\033[1;33mLiteLLM: --ciphers is not applied when using --run_granian.\033[0m\n") + out, err = capfd.readouterr() - assert out == "\n\033[1;32mLiteLLM: Proxy initialized with Config, Set models:\033[0m\n\n" assert err == "" + lines: Final = [raw for raw in out.splitlines() if raw.strip()] + assert len(lines) == 1, lines + if json_logs: + record: Final = json.loads(lines[0]) + assert record["message"] == "LiteLLM: --ciphers is not applied when using --run_granian." + assert record["level"] == "WARNING" + assert str(record["logger"]).startswith("test_logging.py:"), record["logger"] + else: + assert lines[0] == "LiteLLM: --ciphers is not applied when using --run_granian." def test_print_startup_message_is_one_json_record_in_json_mode( @@ -1852,27 +1961,6 @@ def test_print_startup_message_is_one_json_record_in_json_mode( assert str(record["logger"]).startswith("test_logging.py:"), record["logger"] -def test_print_startup_message_yellow_notice_is_an_info_record_on_stdout( - monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] -) -> None: - """An operator notice printed in yellow (an ignored flag, a deprecation) stays on stdout in JSON mode, - where the print put it, as one INFO record with the color codes removed.""" - monkeypatch.setattr(litellm, "json_logs", True) - monkeypatch.setattr(sys, "excepthook", sys.excepthook) - turn_on_json() - verbose_proxy_logger.setLevel(logging.WARNING) - - print_startup_message("\033[1;33mLiteLLM: --ciphers is not applied when using --run_granian.\033[0m\n") - - out, err = capfd.readouterr() - assert err == "" - lines: Final = [raw for raw in out.splitlines() if raw.strip()] - assert len(lines) == 1, lines - record: Final = json.loads(lines[0]) - assert record["message"] == "LiteLLM: --ciphers is not applied when using --run_granian." - assert record["level"] == "INFO" - - def test_print_startup_message_shows_above_the_json_handler_level( monkeypatch: pytest.MonkeyPatch, capfd: pytest.CaptureFixture[str] ) -> None: