This commit is contained in:
Supul Kalhara 2026-09-08 07:04:08 -04:00 committed by GitHub
commit 43187ea1f4
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
5 changed files with 366 additions and 13 deletions

View file

@ -53,6 +53,8 @@ from litellm._logging import (
verbose_logger,
json_logs,
_turn_on_json,
ecs_logs,
_turn_on_ecs, # pyright: ignore[reportPrivateUsage] # re-exported, matches _turn_on_json above
log_level,
)
import re

View file

@ -3,7 +3,7 @@ import contextvars
import logging
import os
import sys
from datetime import datetime
from datetime import datetime, timezone
from logging import Formatter
from typing import Any, Final, TextIO
from urllib.parse import unquote
@ -372,6 +372,8 @@ def _parse_json_logs_env(value: str | None) -> bool:
json_logs: Final = _parse_json_logs_env(os.getenv("JSON_LOGS"))
# LITELLM_ECS_LOGS takes precedence over JSON_LOGS since ECS is a superset of structured JSON.
ecs_logs: Final = _parse_json_logs_env(os.getenv("LITELLM_ECS_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[str] = getattr(logging, log_level.upper())
@ -528,6 +530,65 @@ class CorrelationPlainFormatter(logging.Formatter):
return f"{formatted} [{' '.join(parts)}]"
_ECS_RESERVED_KEYS: Final = frozenset({"@timestamp", "log", "message", "service", "ecs", "error"})
class ECSFormatter(Formatter):
"""Formats log records according to Elastic Common Schema (ECS) v8.x.
Enables structured log ingestion into the Elastic Stack and other ECS-aware
platforms. Activate via the LITELLM_ECS_LOGS=true environment variable or
call _turn_on_ecs() at application startup.
Reference: https://www.elastic.co/guide/en/ecs/current/index.html
"""
ECS_VERSION = "8.11.0"
def __init__(self, service_name: str | None = None) -> None:
super().__init__()
self._service_name = service_name or os.getenv("LITELLM_SERVICE_NAME", "litellm")
def formatTime(self, record: logging.LogRecord, datefmt: str | None = None) -> str:
dt: Final = datetime.fromtimestamp(record.created, tz=timezone.utc)
return dt.strftime("%Y-%m-%dT%H:%M:%S.") + f"{dt.microsecond // 1000:03d}Z"
def format(self, record: logging.LogRecord) -> str:
message_str: Final = record.getMessage()
ecs_record: Final[dict[str, object]] = { # mutable-ok: one-shot, serialized immediately
"@timestamp": self.formatTime(record),
"log": { # mutable-ok: one-shot nested structure
"level": record.levelname.lower(),
"logger": record.name,
"origin": { # mutable-ok: one-shot nested structure
"file": { # mutable-ok: one-shot nested structure
"name": record.filename,
"line": record.lineno,
},
"function": record.funcName,
},
},
"message": message_str,
"service": {"name": self._service_name}, # mutable-ok: one-shot nested structure
"ecs": {"version": self.ECS_VERSION}, # mutable-ok: one-shot nested structure
}
if record.exc_info and record.exc_info[1] is not None:
exc_type, exc_value, _ = record.exc_info
ecs_record["error"] = { # mutable-ok: one-shot, set once and never mutated further
"type": exc_type.__name__ if exc_type else None,
"message": str(exc_value),
"stack_trace": record.exc_text or self.formatException(record.exc_info),
}
for key, value in record.__dict__.items():
if key not in _STANDARD_RECORD_ATTRS and key not in _ECS_RESERVED_KEYS:
ecs_record[key] = value
return safe_dumps(ecs_record, value_transform=_redact_structured_value)
# Function to set up exception handlers for JSON logging
def _setup_json_exception_handlers(formatter):
# Create a handler with JSON formatting for exceptions
@ -578,8 +639,12 @@ def _setup_json_exception_handlers(formatter):
pass
# Create a formatter and set it for the handler
if json_logs:
# Create a formatter and set it for the handler.
# LITELLM_ECS_LOGS takes precedence over JSON_LOGS since ECS is a superset of structured JSON.
if ecs_logs:
handler.setFormatter(ECSFormatter())
_setup_json_exception_handlers(ECSFormatter())
elif json_logs:
handler.setFormatter(JsonFormatter())
_setup_json_exception_handlers(JsonFormatter())
else:
@ -715,12 +780,13 @@ def _initialize_loggers_with_handler(handler: logging.Handler):
def _get_uvicorn_json_log_config():
"""
Generate a uvicorn log_config dictionary that applies JSON formatting to all loggers.
Generate a uvicorn log_config dictionary that applies structured formatting to all loggers.
This ensures that uvicorn's access logs, error logs, and all application logs
are formatted as JSON when json_logs is enabled.
Uses ECSFormatter when LITELLM_ECS_LOGS=true so uvicorn access/error logs
are consistent with application logs for downstream ECS consumers.
Falls back to JsonFormatter when only JSON_LOGS=true.
"""
json_formatter_class: Final = "litellm._logging.JsonFormatter"
formatter_class: Final = "litellm._logging.ECSFormatter" if ecs_logs else "litellm._logging.JsonFormatter"
# Use the module-level log_level variable for consistency
uvicorn_log_level: Final = log_level.upper()
@ -730,13 +796,13 @@ def _get_uvicorn_json_log_config():
"disable_existing_loggers": False,
"formatters": {
"json": {
"()": json_formatter_class,
"()": formatter_class,
},
"default": {
"()": json_formatter_class,
"()": formatter_class,
},
"access": {
"()": json_formatter_class,
"()": formatter_class,
},
},
"handlers": {
@ -783,10 +849,21 @@ def _turn_on_json():
handler.setLevel(numeric_level)
handler.setFormatter(JsonFormatter())
_initialize_loggers_with_handler(handler)
# Set up exception handlers
_setup_json_exception_handlers(JsonFormatter())
def _turn_on_ecs():
"""Switch all litellm loggers to ECS-formatted JSON output.
Idempotent; safe to call multiple times or from sitecustomize.py.
"""
handler: Final = LevelRoutingStreamHandler()
handler.setLevel(numeric_level)
handler.setFormatter(ECSFormatter())
_initialize_loggers_with_handler(handler)
_setup_json_exception_handlers(ECSFormatter())
def _turn_on_debug():
verbose_logger.setLevel(level=logging.DEBUG) # set package log to debug
verbose_router_logger.setLevel(level=logging.DEBUG) # set router logs to debug

View file

@ -266,8 +266,7 @@ class ProxyInitializationHelpers:
if log_config is not None:
print(f"Using log_config: {log_config}")
uvicorn_args["log_config"] = log_config
elif litellm.json_logs:
# Use JSON log config for uvicorn to ensure all logs (including exceptions) are JSON
elif litellm.ecs_logs or litellm.json_logs:
uvicorn_args["log_config"] = _get_uvicorn_json_log_config()
if keepalive_timeout is not None:
uvicorn_args["timeout_keep_alive"] = keepalive_timeout

34
litellm/sitecustomize.py Normal file
View file

@ -0,0 +1,34 @@
"""
ECS logging early-startup hook template for litellm.
This file is a deploy-time template. It will NOT auto-execute from its current
location inside the litellm package. Python only auto-runs sitecustomize.py if
it exists as a top-level module in a site-packages directory.
To enable ECS-compliant log output without touching application code:
1. Find your environment's site-packages path:
python -c "import site; print(site.getsitepackages()[0])"
2. If no sitecustomize.py exists there yet, copy this file:
cp litellm/sitecustomize.py <site-packages>/sitecustomize.py
If one already exists, append this import to it:
echo "import litellm.sitecustomize" >> <site-packages>/sitecustomize.py
3. Set the environment variable before starting your process:
export LITELLM_ECS_LOGS=true
Alternatively, call litellm._logging._turn_on_ecs() directly at the top of
your application's entrypoint if you prefer not to touch site-packages.
"""
import os
if os.environ.get("LITELLM_ECS_LOGS", "").lower() == "true":
try:
from litellm._logging import _turn_on_ecs # pyright: ignore[reportPrivateUsage] # public entry point
_turn_on_ecs()
except Exception:
pass

View file

@ -1,5 +1,6 @@
import ast
import asyncio
import importlib
import json
import logging
import re
@ -20,6 +21,7 @@ from litellm._logging import (
AccessLogRedactionFilter,
CorrelationContextFilter,
CorrelationPlainFormatter,
ECSFormatter,
JsonFormatter,
LevelRoutingStreamHandler,
SecretRedactionFilter,
@ -29,6 +31,7 @@ from litellm._logging import (
_parse_json_logs_env,
_plain_log_format,
_stdout_truncation_marker,
_turn_on_ecs,
_turn_on_json,
session_id_var,
set_session_id,
@ -1178,3 +1181,241 @@ def test_access_redaction_survives_the_uvicorn_json_log_config():
lg.handlers[:] = handlers
lg.setLevel(level)
lg.propagate = True
# ---------------------------------------------------------------------------
# ECS formatter tests
# ---------------------------------------------------------------------------
def test_ecs_formatter_required_fields():
formatter = ECSFormatter()
record = logging.LogRecord(
name="LiteLLM",
level=logging.INFO,
pathname="proxy_server.py",
lineno=42,
msg="test message",
args=(),
exc_info=None,
)
obj = json.loads(formatter.format(record))
assert obj["message"] == "test message"
assert "@timestamp" in obj
assert obj["log"]["level"] == "info"
assert obj["log"]["logger"] == "LiteLLM"
assert obj["log"]["origin"]["file"]["name"] == "proxy_server.py"
assert obj["log"]["origin"]["file"]["line"] == 42
assert obj["service"]["name"] == "litellm"
assert obj["ecs"]["version"] == "8.11.0"
def test_ecs_formatter_timestamp_is_utc_iso8601_with_ms():
formatter = ECSFormatter()
record = logging.LogRecord(
name="LiteLLM",
level=logging.DEBUG,
pathname="",
lineno=0,
msg="ts test",
args=(),
exc_info=None,
)
obj = json.loads(formatter.format(record))
assert re.match(
r"^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z$", obj["@timestamp"]
), f"Non-ECS timestamp: {obj['@timestamp']!r}"
def test_ecs_formatter_log_level_is_lowercase():
formatter = ECSFormatter()
for level, expected in [
(logging.DEBUG, "debug"),
(logging.INFO, "info"),
(logging.WARNING, "warning"),
(logging.ERROR, "error"),
(logging.CRITICAL, "critical"),
]:
record = logging.LogRecord(
name="LiteLLM",
level=level,
pathname="",
lineno=0,
msg="test",
args=(),
exc_info=None,
)
obj = json.loads(formatter.format(record))
assert obj["log"]["level"] == expected
def test_ecs_formatter_error_fields_on_exception():
formatter = ECSFormatter()
try:
raise ValueError("something broke")
except ValueError:
exc_info = sys.exc_info()
record = logging.LogRecord(
name="LiteLLM",
level=logging.ERROR,
pathname="",
lineno=0,
msg="error occurred",
args=(),
exc_info=exc_info,
)
record.exc_text = formatter.formatException(exc_info)
obj = json.loads(formatter.format(record))
assert "error" in obj
assert obj["error"]["type"] == "ValueError"
assert obj["error"]["message"] == "something broke"
assert "stack_trace" in obj["error"]
assert "ValueError" in obj["error"]["stack_trace"]
def test_ecs_formatter_extra_fields_passthrough():
formatter = ECSFormatter()
record = logging.LogRecord(
name="LiteLLM",
level=logging.DEBUG,
pathname="",
lineno=0,
msg="request received",
args=(),
exc_info=None,
)
record.api_base = "https://api.openai.com"
record.model = "gpt-4"
obj = json.loads(formatter.format(record))
assert obj["api_base"] == "https://api.openai.com"
assert obj["model"] == "gpt-4"
def test_ecs_formatter_redacts_a_credential_in_a_structured_extra_value():
"""Parity with JsonFormatter: safe_dumps(value_transform=_redact_structured_value)
must also run for ECS output, or a secret nested in an extra={...} dict leaks."""
formatter = ECSFormatter()
record = logging.LogRecord(
name="LiteLLM",
level=logging.DEBUG,
pathname="",
lineno=0,
msg="request sent",
args=(),
exc_info=None,
)
record.litellm_params = {"api_key": "sk-1234567890abcdefghijklmnopqrstuvwxyz"}
obj = json.loads(formatter.format(record))
assert "sk-1234567890abcdefghijklmnopqrstuvwxyz" not in json.dumps(obj)
assert "REDACTED" in obj["litellm_params"]["api_key"]
def test_ecs_formatter_no_ecs_reserved_key_collision():
formatter = ECSFormatter()
record = logging.LogRecord(
name="LiteLLM",
level=logging.INFO,
pathname="",
lineno=0,
msg="test",
args=(),
exc_info=None,
)
# Attempt to inject via extra - should not overwrite ECS structure
record.message = "injected"
obj = json.loads(formatter.format(record))
assert obj["message"] == "test"
def test_ecs_mode_emits_one_record_per_logger(capfd):
_turn_on_ecs()
for lg in (verbose_logger, verbose_router_logger, verbose_proxy_logger):
lg.setLevel(logging.INFO)
verbose_logger.info("first info")
verbose_router_logger.info("second info from router")
verbose_proxy_logger.info("third info from proxy")
# All three records are INFO, so they must route to stdout and none to stderr
out, err = capfd.readouterr()
assert [raw for raw in err.splitlines() if raw.strip()] == []
lines = [raw for raw in out.splitlines() if raw.strip()]
assert len(lines) == 3, f"got {len(lines)} lines, want 3: {lines!r}"
for line in lines:
obj = json.loads(line)
assert "@timestamp" in obj
assert obj["log"]["level"] == "info"
assert obj["ecs"]["version"] == "8.11.0"
assert obj["service"]["name"] == "litellm"
def test_get_uvicorn_json_log_config_uses_ecs_formatter_when_ecs_logs_enabled(monkeypatch):
"""Regression test: _get_uvicorn_json_log_config() must select ECSFormatter for
every uvicorn formatter entry when LITELLM_ECS_LOGS is on, or uvicorn's own
access/error logs stay plain JSON while application logs are ECS."""
import litellm._logging as litellm_logging
monkeypatch.setattr(litellm_logging, "ecs_logs", True)
log_config = _get_uvicorn_json_log_config()
for formatter_config in log_config["formatters"].values():
assert formatter_config["()"] == "litellm._logging.ECSFormatter"
def _run_sitecustomize_hook():
"""Re-run litellm/sitecustomize.py's module body the way a copy of it in
site-packages runs at interpreter startup."""
return importlib.reload(importlib.import_module("litellm.sitecustomize"))
def _loggers_are_on_ecs() -> bool:
return any(isinstance(handler.formatter, ECSFormatter) for handler in verbose_logger.handlers)
def test_sitecustomize_hook_turns_on_ecs_when_the_env_var_is_set(monkeypatch):
"""The hook is the documented zero-code-change path to ECS logs. Without this,
renaming _turn_on_ecs would leave the hook's except-Exception swallowing the
ImportError and ECS logging would silently never switch on."""
plain = logging.StreamHandler()
plain.setFormatter(JsonFormatter())
_initialize_loggers_with_handler(plain)
monkeypatch.setenv("LITELLM_ECS_LOGS", "true")
_run_sitecustomize_hook()
assert _loggers_are_on_ecs()
def test_sitecustomize_hook_leaves_logging_alone_when_the_env_var_is_unset(monkeypatch):
plain = logging.StreamHandler()
plain.setFormatter(JsonFormatter())
_initialize_loggers_with_handler(plain)
monkeypatch.delenv("LITELLM_ECS_LOGS", raising=False)
_run_sitecustomize_hook()
assert not _loggers_are_on_ecs()
def test_sitecustomize_hook_never_breaks_interpreter_startup(monkeypatch):
"""A copy of this file in site-packages runs for every process in the environment,
so a broken or half-installed litellm must not raise out of it."""
def _raise(*_args, **_kwargs):
raise RuntimeError("litellm is half-installed")
plain = logging.StreamHandler()
plain.setFormatter(JsonFormatter())
_initialize_loggers_with_handler(plain)
monkeypatch.setenv("LITELLM_ECS_LOGS", "true")
monkeypatch.setattr(litellm._logging, "_turn_on_ecs", _raise)
_run_sitecustomize_hook()
assert not _loggers_are_on_ecs()