Merge eb3b2383de into b72c737fc8

litellm/__init__.py

@@ -57,6 +57,7 @@ from litellm._logging import (
     verbose_logger,
     json_logs,
     _turn_on_json,
+    ecs_logs,
     log_level,
 )
 import re

litellm/_logging.py

@@ -7,11 +7,14 @@ import os
 import re
 import sys
 from collections.abc import Iterator
-from datetime import datetime
+from datetime import datetime, timezone
 from logging import Formatter
+from types import MappingProxyType
 from typing import Final, TextIO
 from urllib.parse import unquote
 
+from typing_extensions import ReadOnly, TypedDict
+
 import litellm
 from litellm.constants import (
     LITELLM_TRUNCATED_PAYLOAD_FIELD,
@@ -644,6 +647,7 @@ def resolve_log_level(log_level: str) -> int:
 
 
 json_logs: Final = _parse_json_logs_env(os.getenv("JSON_LOGS"))
+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[int] = resolve_log_level(log_level)
@@ -804,6 +808,94 @@ class CorrelationPlainFormatter(logging.Formatter):
         return f"{formatted} [{' '.join(parts)}]"
 
 
+_ECS_RESERVED_KEYS: Final = frozenset({"@timestamp", "log", "message", "service", "ecs", "error"})
+
+
+class _ECSFile(TypedDict):
+    name: ReadOnly[str]
+    line: ReadOnly[int]
+
+
+class _ECSOrigin(TypedDict):
+    file: ReadOnly[_ECSFile]
+    function: ReadOnly[str]
+
+
+class _ECSLog(TypedDict):
+    level: ReadOnly[str]
+    logger: ReadOnly[str]
+    origin: ReadOnly[_ECSOrigin]
+
+
+class _ECSService(TypedDict):
+    name: ReadOnly[str]
+
+
+class _ECSMeta(TypedDict):
+    version: ReadOnly[str]
+
+
+class _ECSError(TypedDict):
+    type: ReadOnly[str | None]
+    message: ReadOnly[str]
+    stack_trace: ReadOnly[str]
+
+
+class _ECSRecord(TypedDict):
+    log: ReadOnly[_ECSLog]
+    message: ReadOnly[str]
+    service: ReadOnly[_ECSService]
+    ecs: ReadOnly[_ECSMeta]
+
+
+class ECSFormatter(Formatter):
+    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:
+        ecs_fields: Final[_ECSRecord] = {
+            "log": {
+                "level": record.levelname.lower(),
+                "logger": record.name,
+                "origin": {"file": {"name": record.filename, "line": record.lineno}, "function": record.funcName},
+            },
+            "message": record.getMessage(),
+            "service": {"name": self._service_name},
+            "ecs": {"version": self.ECS_VERSION},
+        }
+        extra_fields: Final = MappingProxyType(
+            {
+                key: value
+                for key, value in record.__dict__.items()
+                if key not in _NON_EXTRA_RECORD_ATTRS and key not in _ECS_RESERVED_KEYS
+            }
+        )
+        document: Final = MappingProxyType(
+            {"@timestamp": self.formatTime(record), **ecs_fields, **self._error_fields(record), **extra_fields}
+        )
+        return safe_dumps(
+            document if _is_redacted(record) or not _ENABLE_SECRET_REDACTION else _redact_json_record(document)
+        )
+
+    def _error_fields(self, record: logging.LogRecord) -> MappingProxyType[str, _ECSError]:
+        exc_info: Final = record.exc_info
+        if exc_info is None or exc_info[1] is None:
+            return MappingProxyType({})
+        error: Final[_ECSError] = {
+            "type": exc_info[0].__name__ if exc_info[0] else None,
+            "message": str(exc_info[1]),
+            "stack_trace": record.exc_text or self.formatException(exc_info),
+        }
+        return MappingProxyType({"error": error})
+
+
 # Function to set up exception handlers for JSON logging
 def _setup_json_exception_handlers(formatter):
     # Create a handler with JSON formatting for exceptions
@@ -855,7 +947,10 @@ def _setup_json_exception_handlers(formatter):
 
 
 # Create a formatter and set it for the handler
-if json_logs:
+if ecs_logs:
+    handler.setFormatter(ECSFormatter())
+    _setup_json_exception_handlers(ECSFormatter())
+elif json_logs:
     handler.setFormatter(JsonFormatter())
     _setup_json_exception_handlers(JsonFormatter())
 else:
@@ -997,7 +1092,7 @@ def _get_uvicorn_json_log_config():
     This ensures that uvicorn's access logs, error logs, and all application logs
     are formatted as JSON when json_logs is enabled.
     """
-    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()
@@ -1007,13 +1102,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": {
@@ -1064,6 +1159,14 @@ def _turn_on_json():
     _setup_json_exception_handlers(JsonFormatter())
 
 
+def _turn_on_ecs():
+    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

litellm/litellm_core_utils/litellm_logging.py

@@ -1493,7 +1493,7 @@ class Logging(LiteLLMLoggingBaseClass):
         Prints the RAW curl command sent from LiteLLM
         """
         if _is_debugging_on() or self.litellm_request_debug:
-            if litellm.json_logs:
+            if litellm.json_logs or litellm.ecs_logs:
                 masked_headers: Final = self._get_masked_headers(headers or {})
                 masked_api_base: Final = self._get_masked_api_base(str(api_base or ""))
                 if self.litellm_request_debug:

litellm/litellm_core_utils/safe_json_dumps.py

@@ -1,5 +1,6 @@
 import json
 from collections.abc import Callable
+from types import MappingProxyType
 from typing import Any, Final
 
 from pydantic import BaseModel
@@ -49,7 +50,7 @@ def safe_json_structure(
             return "CircularReference Detected"
         seen.add(id(obj))
         result: dict | list | tuple | set | str
-        if isinstance(obj, dict):
+        if isinstance(obj, (dict, MappingProxyType)):
             result = {}
             for k, v in obj.items():
                 if isinstance(k, (str)):

litellm/proxy/proxy_cli.py

@@ -309,8 +309,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()
         elif litellm_log := os.environ.get("LITELLM_LOG"):
             uvicorn_args["log_level"] = resolve_log_level(litellm_log)

litellm/sitecustomize.py

@@ -0,0 +1,9 @@
+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

tests/unit/litellm_core_utils/test_litellm_logging.py

@@ -9373,3 +9373,32 @@ def test_signoz_dispatch_requires_an_endpoint(monkeypatch):
         logging_module._in_memory_loggers.clear()
         monkeypatch.delenv("LITELLM_OTEL_V2", raising=False)
         is_otel_v2_enabled.cache_clear()
+
+
+def test_ecs_logs_keep_the_request_body_out_of_the_debug_log(logging_obj, monkeypatch):
+    import io
+    import logging
+
+    from litellm._logging import verbose_logger
+
+    monkeypatch.setattr(litellm, "json_logs", False)
+    monkeypatch.setattr(litellm, "ecs_logs", True)
+    logging_obj.litellm_request_debug = True
+    stream = io.StringIO()
+    handler = logging.StreamHandler(stream)
+    verbose_logger.addHandler(handler)
+    try:
+        logging_obj._print_llm_call_debugging_log(
+            api_base="https://api.example.com/v1",
+            headers={},
+            additional_args={
+                "api_base": "https://api.example.com/v1",
+                "headers": {},
+                "complete_input_dict": {"messages": [{"role": "user", "content": "my-private-prompt-text"}]},
+            },
+        )
+    finally:
+        verbose_logger.removeHandler(handler)
+
+    assert "POST Request Sent from LiteLLM" in stream.getvalue()
+    assert "my-private-prompt-text" not in stream.getvalue()

tests/unit/test_logging.py

@@ -2,6 +2,7 @@ import ast
 import asyncio
 import base64
 import dataclasses
+import importlib
 import json
 import logging
 import re
@@ -25,6 +26,7 @@ from litellm._logging import (
     CorrelationContextFilter,
     CorrelationPlainFormatter,
     DiagnosticProcessingFilter,
+    ECSFormatter,
     JsonFormatter,
     LevelRoutingStreamHandler,
     SecretRedactionFilter,
@@ -34,6 +36,7 @@ from litellm._logging import (
     _parse_json_logs_env,
     _plain_log_format,
     _stdout_truncation_marker,
+    _turn_on_ecs,
     _turn_on_json,
     format_base64_size,
     session_id_var,
@@ -1766,3 +1769,223 @@ def test_diagnostic_filter_redacts_a_non_string_message_object(monkeypatch, nati
     assert DiagnosticProcessingFilter().filter(record) is True
 
     assert secret not in record.getMessage()
+
+
+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():
+    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,
+    )
+    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")
+
+    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"
+        assert "litellm_redacted" not in obj
+
+
+def test_get_uvicorn_json_log_config_uses_ecs_formatter_when_ecs_logs_enabled(monkeypatch):
+    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():
+    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):
+    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):
+
+    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()