mirror of
https://github.com/BerriAI/litellm.git
synced 2026-11-02 07:13:02 +00:00
c489aa7117
* fix(proxy): keep every startup line JSON when json_logs is on Boot-time messages the proxy printed straight to stdout (banner, feedback box, model list, cache and callback notices, policy table, migration notices, CLI launch notes) and the first records of uvicorn- or granian-spawned workers came out as plain text while json_logs was on, breaking log pipelines that parse every line as JSON. - print_startup_message() prints unchanged in plain mode and, with json_logs on, emits one INFO record on the proxy logger (ANSI stripped) that skips the logger and handler level checks like the print it replaces; show_banner() routes to it in JSON mode only - the CLI exports JSON_LOGS=true when the config sets json_logs so spawned workers log JSON from their first record - the --enforce_prisma_migration_check deprecation notice prints after the config is read so a config-only json_logs covers it Resolves LIT-1624 * fix(proxy): keep show_banner() SDK-free, pick the JSON banner in initialize() Since #46803 the `lite` shell calls show_banner() against an uninitialized litellm package, and reading litellm.json_logs inside it initialized the whole SDK at the banner (0.14 s to 0.83 s for a bare `lite` here, the seconds that PR removed on small VMs). show_banner() is back to its main version; the proxy's initialize() now emits the JSON banner record itself and calls show_banner() only in plain mode. The banner unit tests move to the initialize() call site. * fix(proxy): keep the JSON banner when an operator --log_config names the proxy logger uvicorn applies --log_config after proxy_cli has switched JSON logging on and before initialize() switches it on again through load_config(). A logging config that names "LiteLLM Proxy" removes that logger's handlers in the window between the two, which is where initialize() emits the banner and the feedback box, so at one worker both went nowhere; two-worker children import litellm after uvicorn's logging setup and were not affected. print_startup_message() now falls back to a one-off JSON handler, on the stream the JSON handler uses, when the proxy logger has no handler of its own. Live, json_logs on plus a log_config naming the proxy logger, one worker: main prints the banner and the feedback box as plaintext,e2303a3925prints neither, this head prints both as one JSON record each. New unit test fails on e2303a3925; new integration cell test_json_logs_with_operator_log_config_keeps_every_line_json passes at one and two workers. * fix(proxy): keep a long startup listing whole in its JSON record print_startup_message ran its record through the proxy logger's filters, so in JSON mode the required-migration SQL list and the policy list were middle-truncated at MAX_STRING_LENGTH_STDOUT_LOG (4096 by default) with the litellm_truncated marker, where the prints they replace showed them whole. That cap bounds echoed request payloads; a startup message is operator text, so the record now gets the uncapped processing of a DEBUG line: secret redaction and base64 collapse still apply, the text cap does not. Red on41f92b745a, green here: - tests/unit/test_logging.py: a listing longer than the cap comes out whole; a credential in a startup message is still redacted - tests/integration/configuration/test_json_logs_startup.py: a 60-policy config boots with json_logs on and the policy listing record (9762 chars) carries every policy with no truncation marker (4096 chars, marker, on the unfixed tree) * fix(proxy): keep the --enforce_prisma_migration_check notice on --health and --test This PR moved the deprecation notice after the config is read, so that a json_logs set only in the config applies to it; --health and --test return before that point and stopped printing it, a visible change main did not have. The notice is now also emitted before those two returns, through the same helper, so a deployment running `litellm --health --enforce_prisma_migration_check` still learns the flag is dead, as on main. A normal server start emits it once, after the config, as in the previous commit. Red on2d7a2d6844, green here: tests/unit/proxy/test_proxy_cli.py asserts the notice on --health and on --test. * fix(proxy): keep the JSON startup records on stdout under an operator handler on the proxy logger An operator --log_config that gives "LiteLLM Proxy" a handler of its own, a NullHandler that silences it or a plain WARNING-level handler on stderr, is in force in the window where the banner, the feedback box and the cache notice are emitted: uvicorn applies it after the CLI process switched JSON on and before initialize() re-installs the JSON handler through load_config().41f92b745asent the startup records through the proxy logger's handlers and fell back to a JSON stdout handler only when there were none, so under such a config the records landed in the operator's handler, as plaintext on stderr, or vanished, where the prints they replace reached stdout whatever the logging config said. print_startup_message() now writes every startup record through the proxy's own JSON handler on stdout, filters included, and never through the proxy logger's handlers; the operator's handler gets nothing from a startup message, as it got nothing from the print. The normal JSON handler is the same class, formatter and filters, so the records a pipeline reads are unchanged when no operator config is in play. Tests: tests/unit/test_logging.py gets the two handler shapes (red onf6f5957d16: the record went to stderr as plaintext or nowhere); tests/integration/configuration/ test_json_logs_startup.py gets a silencing operator --log_config cell at 1 and 2 workers (red onf6f5957d16: banner, feedback box and cache notice missing; green here). * fix(proxy): print the --enforce_prisma_migration_check notice when the config fails to loadf6f5957d16printed the deprecation notice after the config is read, so a json_logs set only in the config makes it a JSON record. A boot whose config file is missing or does not parse then exited before that point and never printed it, where main printed it before the error (10-20 gauntlet finding). The notice is printed where main printed it, unless a config file can still switch json_logs on: then it is held until the config is read and printed right after the json_logs switch, and a click close callback prints it on the way out if the boot fails first. functools.cache keeps it to one print either way. Tests: tests/unit/proxy/test_proxy_cli.py covers a failed config read (red on75043aed83), a plain config printing it once and a config-only json_logs making it one JSON record; tests/integration/configuration/test_json_logs_startup.py adds the JSON cell and a missing and an unparseable config cell (red on75043aed83, green here), through refused_boot_log, which now takes extra CLI arguments. * feat(proxy): add suppress_startup_output to turn off startup prints * fix(proxy): print startup messages once and without color codes off a terminal * test(policy-engine): check the policy table keeps colors on a terminal and drops them on a pipe * fix(proxy): keep startup warnings when suppress_startup_output is on and apply it from CONFIG_FILE_PATH and before other settings Warnings that name something the operator must fix now print through print_startup_warning, which skips the suppress gate. The config key is read with the CLI's json_logs handling for --config and CONFIG_FILE_PATH, applied before the rest of litellm_settings in load_config, and can only turn the setting on. The Prometheus config panel obeys the setting, and startup prints use the plain log format's color rule. * fix(proxy): read CONFIG_FILE_PATH in the CLI only when workers would load it Workers load CONFIG_FILE_PATH only when it names an existing YAML file, so the CLI's early read of json_logs and suppress_startup_output skips any other value instead of failing a boot that used to start. * fix(proxy): read only suppress_startup_output from CONFIG_FILE_PATH in the CLI, without secrets The CLI now reads CONFIG_FILE_PATH as a plain file with its includes, skips it when a config bucket is set, and applies only suppress_startup_output, also when --config is passed. json_logs there stays with the workers as before. Fatal boot errors drop their color codes off a terminal like the startup prints. * fix(logging): emit startup warnings as WARNING records in JSON mode * fix(proxy): keep one JSON record per search tool in the startup listing * fix(proxy): keep booting with an ASCII stdout or an empty litellm_settings Startup messages now go through click.echo, which writes UTF-8 when stdout is ASCII, as the banner did before. An empty litellm_settings section reads as no settings in the CLI, as the workers already read it * test(proxy): boot the CLI tests on the real ProxyConfig config readers * test(proxy): cover the startup warnings that print with startup output suppressed * test(proxy): boot the deprecated resolver flag test on the real ProxyConfig * test(proxy): drop the startup output contract's narrating docstrings * test(proxy): cover the pgbouncer start failure message off a terminal --------- Co-authored-by: yucheng-berri <293926326+yucheng-berri@users.noreply.github.com>
107 lines
4.2 KiB
Python
107 lines
4.2 KiB
Python
import json
|
|
import logging
|
|
import sys
|
|
from typing import Final
|
|
|
|
import pytest
|
|
|
|
import litellm
|
|
from litellm._logging import turn_on_json, verbose_logger, verbose_proxy_logger
|
|
|
|
|
|
def test_check_migration_out_of_sync(mocker):
|
|
"""
|
|
Test that the check_prisma_schema_diff function
|
|
- 🚨 [IMPORTANT] Does NOT Raise an Exception when the Prisma schema is out of sync with the database.
|
|
- logs an error when the Prisma schema is out of sync with the database.
|
|
"""
|
|
# Import the module first so check_migration is in sys.modules,
|
|
# then patch the logger reference in that module directly (not the source
|
|
# module) so the patch works regardless of import order or xdist worker
|
|
# assignment.
|
|
from litellm.proxy.db import check_migration
|
|
|
|
# Mock the helper function to simulate out-of-sync state
|
|
mock_logger = mocker.patch.object(
|
|
check_migration,
|
|
"verbose_logger",
|
|
autospec=True,
|
|
)
|
|
mocker.patch.object(
|
|
check_migration,
|
|
"check_prisma_schema_diff_helper",
|
|
return_value=(True, ["ALTER TABLE users ADD COLUMN new_field TEXT;"]),
|
|
)
|
|
|
|
# Run the function - it should not raise an error
|
|
try:
|
|
check_migration.check_prisma_schema_diff(db_url="mock_url")
|
|
except Exception as e:
|
|
pytest.fail(f"check_prisma_schema_diff raised an unexpected exception: {e}")
|
|
|
|
# Verify the logger was called with the expected message
|
|
check_migration.verbose_logger.exception.assert_called_once()
|
|
actual_message = check_migration.verbose_logger.exception.call_args[0][0]
|
|
assert "prisma schema out of sync with db" in actual_message
|
|
|
|
|
|
@pytest.mark.timeout(30)
|
|
def test_migrate_diff_stops_at_its_budget_and_takes_its_process_tree_with_it(fake_prisma_cli, monkeypatch):
|
|
"""
|
|
`prisma migrate diff` ran unbounded, so a database that never answers hung boot
|
|
before uvicorn ever started, and interrupting the proxy orphaned the schema engine.
|
|
"""
|
|
from litellm.proxy.db.check_migration import check_prisma_schema_diff_helper
|
|
|
|
monkeypatch.setenv("FAKE_PRISMA_HANG_FIRST", "1")
|
|
|
|
assert check_prisma_schema_diff_helper("postgresql://u:p@localhost:9/x") == (False, [])
|
|
assert fake_prisma_cli.calls == [
|
|
["migrate", "diff", "--from-url", "postgresql://u:p@localhost:9/x",
|
|
"--to-schema-datamodel", "./schema.prisma", "--script"]
|
|
]
|
|
assert fake_prisma_cli.grandchild_is_gone(within_seconds=5)
|
|
|
|
|
|
def test_migrate_diff_without_the_prisma_runner_skips_instead_of_crashing_boot(monkeypatch):
|
|
"""
|
|
Boot calls this helper directly, so an ImportError here takes the proxy down before
|
|
uvicorn starts. An install without the runner must lose the diagnostic, not the proxy.
|
|
"""
|
|
import sys
|
|
|
|
from litellm.proxy.db.check_migration import check_prisma_schema_diff_helper
|
|
|
|
monkeypatch.setitem(sys.modules, "litellm_proxy_extras.prisma_toolchain", None)
|
|
|
|
assert check_prisma_schema_diff_helper("postgresql://u:p@localhost:9/x") == (False, [])
|
|
|
|
|
|
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 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
|
|
|
|
monkeypatch.setitem(sys.modules, "litellm_proxy_extras.prisma_toolchain", None)
|
|
monkeypatch.setattr(litellm, "json_logs", True)
|
|
monkeypatch.setattr(sys, "excepthook", sys.excepthook)
|
|
turn_on_json()
|
|
verbose_logger.setLevel(logging.WARNING)
|
|
verbose_proxy_logger.setLevel(logging.WARNING)
|
|
|
|
assert check_prisma_schema_diff_helper("postgresql://u:p@localhost:9/x") == (False, [])
|
|
|
|
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["level"], record["message"]) == (
|
|
"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",
|
|
)
|