From b5e983fcd8c7898d6b4ec30e996ff9c328d5b7a7 Mon Sep 17 00:00:00 2001 From: AngeloDanducci Date: Wed, 22 Apr 2026 17:04:48 -0400 Subject: [PATCH 1/2] add additional logging handlers --- docs/examples/plugins/class_plugin.py | 2 +- docs/examples/plugins/execution_modes.py | 2 +- docs/examples/plugins/payload_modification.py | 2 +- docs/examples/plugins/plugin_scoped.py | 2 +- .../plugins/plugin_set_composition.py | 2 +- docs/examples/plugins/quickstart.py | 2 +- docs/examples/plugins/session_scoped.py | 2 +- docs/examples/plugins/standalone_hooks.py | 2 +- docs/examples/plugins/tool_hooks.py | 2 +- mellea/core/utils.py | 281 ++++++--- mellea/telemetry/__init__.py | 2 +- mellea/telemetry/logging.py | 58 +- test/core/test_logger_plugin_hooks.py | 8 +- test/core/test_utils_logging.py | 535 +++++++++++++++++- test/telemetry/test_logging.py | 52 +- 15 files changed, 787 insertions(+), 167 deletions(-) diff --git a/docs/examples/plugins/class_plugin.py b/docs/examples/plugins/class_plugin.py index 59c07326f..59ace83e1 100644 --- a/docs/examples/plugins/class_plugin.py +++ b/docs/examples/plugins/class_plugin.py @@ -22,7 +22,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("class_plugin") diff --git a/docs/examples/plugins/execution_modes.py b/docs/examples/plugins/execution_modes.py index 94ca8d545..d6f0e2ea6 100644 --- a/docs/examples/plugins/execution_modes.py +++ b/docs/examples/plugins/execution_modes.py @@ -36,7 +36,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("execution_modes") diff --git a/docs/examples/plugins/payload_modification.py b/docs/examples/plugins/payload_modification.py index fd7569c9c..f4d9cf938 100644 --- a/docs/examples/plugins/payload_modification.py +++ b/docs/examples/plugins/payload_modification.py @@ -28,7 +28,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("payload_modification") diff --git a/docs/examples/plugins/plugin_scoped.py b/docs/examples/plugins/plugin_scoped.py index 93757bc1c..cc320685e 100644 --- a/docs/examples/plugins/plugin_scoped.py +++ b/docs/examples/plugins/plugin_scoped.py @@ -35,7 +35,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("plugin_scoped") diff --git a/docs/examples/plugins/plugin_set_composition.py b/docs/examples/plugins/plugin_set_composition.py index 686796ff8..2e3749593 100644 --- a/docs/examples/plugins/plugin_set_composition.py +++ b/docs/examples/plugins/plugin_set_composition.py @@ -30,7 +30,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("plugin_set") diff --git a/docs/examples/plugins/quickstart.py b/docs/examples/plugins/quickstart.py index 66d8e4084..c68202467 100644 --- a/docs/examples/plugins/quickstart.py +++ b/docs/examples/plugins/quickstart.py @@ -19,7 +19,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("quickstart") diff --git a/docs/examples/plugins/session_scoped.py b/docs/examples/plugins/session_scoped.py index 02e8a0bba..96c943dbc 100644 --- a/docs/examples/plugins/session_scoped.py +++ b/docs/examples/plugins/session_scoped.py @@ -29,7 +29,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("session_scoped") diff --git a/docs/examples/plugins/standalone_hooks.py b/docs/examples/plugins/standalone_hooks.py index 0166183a5..1d1147f20 100644 --- a/docs/examples/plugins/standalone_hooks.py +++ b/docs/examples/plugins/standalone_hooks.py @@ -28,7 +28,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("standalone_hooks") diff --git a/docs/examples/plugins/tool_hooks.py b/docs/examples/plugins/tool_hooks.py index fcd2e2fad..3b574ba75 100644 --- a/docs/examples/plugins/tool_hooks.py +++ b/docs/examples/plugins/tool_hooks.py @@ -40,7 +40,7 @@ datefmt="%Y-%m-%dT%H:%M:%S", ) logging.getLogger("httpx").setLevel(logging.ERROR) -logging.getLogger("fancy_logger").setLevel(logging.ERROR) +logging.getLogger("mellea").setLevel(logging.ERROR) log = logging.getLogger("tool_hooks") diff --git a/mellea/core/utils.py b/mellea/core/utils.py index 67f580811..d18800c9c 100644 --- a/mellea/core/utils.py +++ b/mellea/core/utils.py @@ -1,20 +1,46 @@ """Logging utilities for the mellea core library. -Provides ``MelleaLogger``, a singleton logger with colour-coded console output and -an optional REST handler (``RESTHandler``) that forwards log records to a local -``/api/receive`` endpoint when the ``MELLEA_FLOG`` environment variable is set. All -internal mellea modules obtain their logger via ``MelleaLogger.get_logger()``. +Provides ``MelleaLogger``, a singleton logger with colour-coded console output, +an optional rotating file handler, and optional OTLP / webhook forwarding. +All internal mellea modules obtain their logger via ``MelleaLogger.get_logger()``. + +Handler setup is performed by :func:`configure_logging`, which is called +automatically on the first :meth:`MelleaLogger.get_logger` invocation. Environment variables --------------------- +``MELLEA_LOG_ENABLED`` + Master switch for all logging handlers. Set to ``false`` / ``0`` / ``no`` to + suppress all handlers (useful in test environments). Defaults to ``true``. ``MELLEA_LOG_LEVEL`` Minimum log level name (e.g. ``DEBUG``, ``INFO``, ``WARNING``). Defaults to ``INFO``. ``MELLEA_LOG_JSON`` - Set to any truthy value (``1``, ``true``, ``yes``) to emit structured JSON on - the console instead of the colour-coded human-readable format. + Set to any truthy value (``1``, ``true``, ``yes``) to emit structured JSON + instead of colour-coded human-readable text. Applies to both the console and + file handlers. +``MELLEA_LOG_CONSOLE`` + Set to ``false`` / ``0`` / ``no`` to disable the console (stdout) handler. + Defaults to ``true``. +``MELLEA_LOG_FILE`` + Absolute or relative path for rotating file output (e.g. + ``/var/log/mellea.log``). When unset no file handler is attached. +``MELLEA_LOG_FILE_MAX_BYTES`` + Maximum size in bytes before the log file is rotated. Defaults to + ``10485760`` (10 MB). +``MELLEA_LOG_FILE_BACKUP_COUNT`` + Number of rotated backup files to keep. Defaults to ``5``. +``MELLEA_LOG_OTLP`` + Set to ``true`` / ``1`` / ``yes`` to export logs via OpenTelemetry Logs + Protocol. Requires ``opentelemetry-sdk`` and an OTLP endpoint configured + via ``OTEL_EXPORTER_OTLP_LOGS_ENDPOINT`` or ``OTEL_EXPORTER_OTLP_ENDPOINT``. +``MELLEA_LOG_WEBHOOK`` + HTTP(S) URL to forward log records to via HTTP POST. When set a + :class:`RESTHandler` is attached. Supersedes the deprecated ``MELLEA_FLOG`` + and ``FLOG`` variables. ``MELLEA_FLOG`` - When set, log records are forwarded to a local REST endpoint. + Deprecated alias for ``MELLEA_LOG_WEBHOOK``. Activates a ``RESTHandler`` + pointed at ``http://localhost:8000/api/receive``. """ import contextlib @@ -24,7 +50,9 @@ import os import sys import threading +import warnings from collections.abc import Generator +from logging.handlers import RotatingFileHandler as _RotatingFileHandler from typing import Any import requests @@ -36,6 +64,7 @@ except ImportError: _OTEL_AVAILABLE = False +from ..telemetry import get_otlp_log_handler from ..telemetry.context import _CONTEXT_VARS as _telemetry_vars, MelleaContextFilter # --------------------------------------------------------------------------- @@ -203,11 +232,13 @@ def filter(self, record: logging.LogRecord) -> bool: class RESTHandler(logging.Handler): - """Logging handler that forwards records to a local REST endpoint. + """Logging handler that forwards records to an HTTP endpoint unconditionally. + + Attach this handler only when a webhook URL is configured; it sends every + record it receives. Use :func:`configure_logging` or + :meth:`MelleaLogger.get_logger` to obtain a pre-configured instance. - Sends log records as JSON to ``/api/receive`` when the ``MELLEA_FLOG`` environment - variable is set. Failures are silently suppressed to avoid disrupting the - application. + Failures are silently suppressed to avoid disrupting the application. Args: api_url (str): The URL of the REST endpoint that receives log records. @@ -226,29 +257,29 @@ def __init__( self.headers = headers or {"Content-Type": "application/json"} def emit(self, record: logging.LogRecord) -> None: - """Forwards a log record to the REST endpoint when the ``MELLEA_FLOG`` environment variable is set. + """Forward *record* to the configured REST endpoint. - Silently suppresses any network or HTTP errors to avoid disrupting the application. + Silently suppresses any network or HTTP errors to avoid disrupting + the application. Args: record (logging.LogRecord): The log record to forward. """ - if _check_flog_env(): - formatter = self.formatter - if isinstance(formatter, JsonFormatter): - log_dict = formatter.format_as_dict(record) - else: - log_dict = {"message": self.format(record)} - try: - response = requests.request( - self.method, - self.api_url, - headers=self.headers, - data=json.dumps([log_dict]), - ) - response.raise_for_status() - except requests.exceptions.RequestException as _: - pass + formatter = self.formatter + if isinstance(formatter, JsonFormatter): + log_dict = formatter.format_as_dict(record) + else: + log_dict = {"message": self.format(record)} + try: + response = requests.request( + self.method, + self.api_url, + headers=self.headers, + data=json.dumps([log_dict]), + ) + response.raise_for_status() + except requests.exceptions.RequestException: + pass class JsonFormatter(logging.Formatter): @@ -463,13 +494,137 @@ def format(self, record: logging.LogRecord) -> str: return result +def _parse_bool_env(value: str, default: bool = True) -> bool: + """Parse an environment variable string as a boolean. + + Args: + value: Raw environment variable string (may be empty). + default: Value to return when *value* is empty or unrecognised. + + Returns: + bool: Parsed boolean value. + """ + v = value.strip().lower() + if v in ("1", "true", "yes"): + return True + if v in ("0", "false", "no"): + return False + return default + + +def _resolve_webhook_url() -> str | None: + """Return the configured webhook URL, with deprecated-variable fallbacks. + + Checks in priority order: + + 1. ``MELLEA_LOG_WEBHOOK`` — the canonical variable. + 2. ``MELLEA_FLOG`` — deprecated; emits :class:`DeprecationWarning` and + returns ``http://localhost:8000/api/receive``. + 3. ``FLOG`` — deprecated; emits :class:`DeprecationWarning` and returns + ``http://localhost:8000/api/receive``. + + Returns: + str | None: The URL to POST log records to, or ``None`` if no webhook + is configured. + """ + url = os.environ.get("MELLEA_LOG_WEBHOOK", "").strip() + if url: + return url + + if os.environ.get("MELLEA_FLOG"): + warnings.warn( + "MELLEA_FLOG is deprecated and will be removed in a future release. " + "Use MELLEA_LOG_WEBHOOK instead.", + DeprecationWarning, + stacklevel=2, + ) + return "http://localhost:8000/api/receive" + + if os.environ.get("FLOG"): + warnings.warn( + "FLOG is deprecated and will be removed in a future release. " + "Use MELLEA_LOG_WEBHOOK instead.", + DeprecationWarning, + stacklevel=2, + ) + return "http://localhost:8000/api/receive" + + return None + + +def configure_logging(logger: logging.Logger) -> None: + """Attach log handlers to *logger* based on current environment variables. + + It always appends new handlers (the caller is responsible for clearing + existing ones before re-configuring). It is called automatically by + :meth:`MelleaLogger.get_logger` and is also available for programmatic use. + + When ``MELLEA_LOG_ENABLED`` is falsy no handlers are attached; the logger + still exists and accepts records, but they are silently discarded. + + Args: + logger: The :class:`logging.Logger` to configure. + """ + if not _parse_bool_env(os.environ.get("MELLEA_LOG_ENABLED", ""), default=True): + return + + use_json = _parse_bool_env(os.environ.get("MELLEA_LOG_JSON", ""), default=False) + + # --- Webhook / REST handler --- + webhook_url = _resolve_webhook_url() + if webhook_url: + rest_handler = RESTHandler(webhook_url) + rest_handler.setFormatter(JsonFormatter()) + logger.addHandler(rest_handler) + + # --- Console / stream handler --- + if _parse_bool_env(os.environ.get("MELLEA_LOG_CONSOLE", ""), default=True): + stream_handler = logging.StreamHandler(stream=sys.stdout) + if use_json: + stream_handler.setFormatter(JsonFormatter()) + else: + stream_handler.setFormatter(CustomFormatter(datefmt="%H:%M:%S,%03d")) + logger.addHandler(stream_handler) + + # --- Optional rotating file handler --- + log_file = os.environ.get("MELLEA_LOG_FILE", "").strip() + if log_file: + try: + max_bytes = int(os.environ.get("MELLEA_LOG_FILE_MAX_BYTES", "10485760")) + backup_count = int(os.environ.get("MELLEA_LOG_FILE_BACKUP_COUNT", "5")) + file_handler = _RotatingFileHandler( + log_file, maxBytes=max_bytes, backupCount=backup_count + ) + if use_json: + file_handler.setFormatter(JsonFormatter()) + else: + file_handler.setFormatter( + logging.Formatter( + "%(asctime)s - %(levelname)s - %(message)s", + datefmt="%Y-%m-%dT%H:%M:%S", + ) + ) + logger.addHandler(file_handler) + except (ValueError, OSError) as exc: + warnings.warn( + f"Failed to configure file logging handler for {log_file!r}: {exc}. " + "File logging will be skipped.", + UserWarning, + stacklevel=2, + ) + + # --- Optional OTLP handler --- + otlp_handler = get_otlp_log_handler() + if otlp_handler: + logger.addHandler(otlp_handler) + + class MelleaLogger: - """Singleton logger with colour-coded console output and optional REST forwarding. + """Singleton logger with colour-coded console output and configurable handlers. Obtain the shared logger instance via ``MelleaLogger.get_logger()``. Log level - defaults to ``INFO`` but can be overridden via ``MELLEA_LOG_LEVEL``. When the - ``MELLEA_FLOG`` environment variable is set, records are also forwarded to a - local ``/api/receive`` REST endpoint via ``RESTHandler``. + defaults to ``INFO`` but can be overridden via ``MELLEA_LOG_LEVEL``. Handler + setup is delegated to :func:`configure_logging`. Attributes: logger (logging.Logger | None): The shared ``logging.Logger`` instance; ``None`` until first call to ``get_logger()``. @@ -512,76 +667,38 @@ def _resolve_log_level() -> int: @staticmethod def get_logger() -> logging.Logger: - """Returns a MelleaLogger.logger and sets level based upon env vars. + """Return the shared :class:`logging.Logger`, creating it on first call. The logger is created once (singleton). Subsequent calls return the cached instance. Initialisation is protected by a module-level lock so concurrent callers at startup cannot create duplicate handlers. + When ``MELLEA_LOG_ENABLED`` is falsy :func:`configure_logging` attaches + no handlers — the logger still exists, but records are silently + discarded (useful for tests or environments that must produce no output). + Returns: - Configured logger with REST, stream, and optional OTLP handlers. + Configured logger instance. """ if MelleaLogger.logger is None: with _logger_lock: # Second check inside the lock: another thread may have finished # initialisation while we were waiting. if MelleaLogger.logger is None: - logger = logging.getLogger("fancy_logger") + logger = logging.getLogger("mellea") - # Attach both filters so they reach all handlers + # Filters belong to the logger so every handler receives + # trace and Mellea context regardless of which handler + # processes the record. logger.addFilter(ContextFilter()) logger.addFilter(OtelTraceFilter()) - - # Inject telemetry context fields (session_id, request_id, etc.) logger.addFilter(MelleaContextFilter()) # Only set default level if user hasn't already configured it if logger.level == logging.NOTSET: logger.setLevel(MelleaLogger._resolve_log_level()) - # --- REST handler --- - api_url = "http://localhost:8000/api/receive" - rest_handler = RESTHandler(api_url) - rest_handler.setFormatter(JsonFormatter()) - logger.addHandler(rest_handler) - - # --- Console / stream handler --- - stream_handler = logging.StreamHandler(stream=sys.stdout) - use_json_console = os.environ.get( - "MELLEA_LOG_JSON", "" - ).strip().lower() in ("1", "true", "yes") - if use_json_console: - stream_handler.setFormatter(JsonFormatter()) - else: - stream_handler.setFormatter( - CustomFormatter(datefmt="%H:%M:%S,%03d") - ) - logger.addHandler(stream_handler) - - # --- Optional OTLP handler --- - from ..telemetry import get_otlp_log_handler - - otlp_handler = get_otlp_log_handler() - if otlp_handler: - otlp_handler.setFormatter(JsonFormatter()) - logger.addHandler(otlp_handler) + configure_logging(logger) MelleaLogger.logger = logger return MelleaLogger.logger - - -def _check_flog_env() -> bool: - """Check MELLEA_FLOG, with a DeprecationWarning fallback for the old FLOG name.""" - if os.environ.get("MELLEA_FLOG"): - return True - if os.environ.get("FLOG"): - import warnings - - warnings.warn( - "The FLOG environment variable is deprecated and will be removed in a future release. " - "Use MELLEA_FLOG instead.", - DeprecationWarning, - stacklevel=2, - ) - return True - return False diff --git a/mellea/telemetry/__init__.py b/mellea/telemetry/__init__.py index 110f40d1a..d392baa36 100644 --- a/mellea/telemetry/__init__.py +++ b/mellea/telemetry/__init__.py @@ -33,7 +33,7 @@ - MELLEA_PRICING_FILE: Path to a JSON file with custom model pricing overrides (optional) Logging: - - MELLEA_LOGS_OTLP: Enable OTLP log export (default: false) + - MELLEA_LOG_OTLP: Enable OTLP log export (default: false) - OTEL_EXPORTER_OTLP_LOGS_ENDPOINT: Logs-specific endpoint (optional) - OTEL_EXPORTER_OTLP_ENDPOINT: General OTLP endpoint (fallback) - OTEL_SERVICE_NAME: Service name for logs (default: mellea) diff --git a/mellea/telemetry/logging.py b/mellea/telemetry/logging.py index 0fea4b6c0..12b7615ab 100644 --- a/mellea/telemetry/logging.py +++ b/mellea/telemetry/logging.py @@ -3,13 +3,13 @@ Provides log export using OpenTelemetry Logs API with OTLP exporter support. Configuration via environment variables: -- MELLEA_LOGS_OTLP: Enable OTLP logs exporter (default: false) +- MELLEA_LOG_OTLP: Enable OTLP logs exporter (default: false) - OTEL_EXPORTER_OTLP_LOGS_ENDPOINT: Logs-specific endpoint (optional, overrides general) - OTEL_EXPORTER_OTLP_ENDPOINT: General endpoint for all signals (fallback) - OTEL_SERVICE_NAME: Service name for logs (default: mellea) Example: - export MELLEA_LOGS_OTLP=true + export MELLEA_LOG_OTLP=true export OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 Programmatic usage: @@ -39,41 +39,38 @@ except ImportError: _OTEL_AVAILABLE = False -# Configuration from environment variables -_LOGS_OTLP = _OTEL_AVAILABLE and os.getenv("MELLEA_LOGS_OTLP", "false").lower() in ( - "true", - "1", - "yes", -) -_OTLP_LOGS_ENDPOINT = os.getenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT") or os.getenv( - "OTEL_EXPORTER_OTLP_ENDPOINT" -) -_SERVICE_NAME = os.getenv("OTEL_SERVICE_NAME", "mellea") - def _setup_logger_provider() -> Any: """Set up the LoggerProvider with OTLP exporter. + Reads endpoint and service-name env vars at call time so that env changes + made after module import (e.g. in tests) are respected. + Returns: - LoggerProvider instance or None if OpenTelemetry is not available or no endpoint configured + LoggerProvider instance or None if OpenTelemetry is not available or + no endpoint is configured. """ if not _OTEL_AVAILABLE: return None - if not _OTLP_LOGS_ENDPOINT: + endpoint = os.getenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT") or os.getenv( + "OTEL_EXPORTER_OTLP_ENDPOINT" + ) + if not endpoint: warnings.warn( - "OTLP logs exporter is enabled (MELLEA_LOGS_OTLP=true) but no endpoint is configured. " + "OTLP logs exporter is enabled (MELLEA_LOG_OTLP=true) but no endpoint is configured. " "Set OTEL_EXPORTER_OTLP_LOGS_ENDPOINT or OTEL_EXPORTER_OTLP_ENDPOINT to export logs.", UserWarning, - stacklevel=2, + stacklevel=3, ) return None - resource = Resource.create({"service.name": _SERVICE_NAME}) # type: ignore + service_name = os.getenv("OTEL_SERVICE_NAME", "mellea") + resource = Resource.create({"service.name": service_name}) # type: ignore logger_provider = LoggerProvider(resource=resource) # type: ignore try: - otlp_exporter = OTLPLogExporter(endpoint=_OTLP_LOGS_ENDPOINT) # type: ignore + otlp_exporter = OTLPLogExporter(endpoint=endpoint) # type: ignore logger_provider.add_log_record_processor( BatchLogRecordProcessor(otlp_exporter) # type: ignore ) @@ -82,7 +79,7 @@ def _setup_logger_provider() -> Any: f"Failed to initialize OTLP logs exporter: {e}. " "Logs will not be exported via OTLP.", UserWarning, - stacklevel=2, + stacklevel=3, ) return None @@ -90,16 +87,18 @@ def _setup_logger_provider() -> Any: return logger_provider -# Initialize logger provider if OTLP logging is enabled -_logger_provider = None - -if _LOGS_OTLP: - _logger_provider = _setup_logger_provider() +# Lazily initialised on first call to get_otlp_log_handler(). +_logger_provider: Any = None +_logger_provider_initialised: bool = False def get_otlp_log_handler() -> Any: """Get an OTLP logging handler for Python's logging module. + The logger provider is initialised on the first call so that environment + variables set after module import (e.g. ``MELLEA_LOG_OTLP``) are + respected without requiring a module reload. + Returns: LoggingHandler instance if OTLP logging is enabled and configured, None otherwise. @@ -114,6 +113,15 @@ def get_otlp_log_handler() -> Any: logger.addHandler(handler) logger.info("This log will be exported via OTLP") """ + global _logger_provider, _logger_provider_initialised + if not _logger_provider_initialised: + _logger_provider_initialised = True + logs_otlp = _OTEL_AVAILABLE and os.getenv( + "MELLEA_LOG_OTLP", "false" + ).lower() in ("true", "1", "yes") + if logs_otlp: + _logger_provider = _setup_logger_provider() + if _logger_provider is None: return None diff --git a/test/core/test_logger_plugin_hooks.py b/test/core/test_logger_plugin_hooks.py index 888252bcf..2521e5212 100644 --- a/test/core/test_logger_plugin_hooks.py +++ b/test/core/test_logger_plugin_hooks.py @@ -113,7 +113,7 @@ async def log_hook(payload: Any, ctx: Any) -> None: register(log_hook) - with caplog.at_level(logging.INFO, logger="fancy_logger"): + with caplog.at_level(logging.INFO, logger="mellea"): await RejectionSamplingStrategy(loop_budget=1).sample( Instruction("test"), context=SimpleContext(), @@ -143,7 +143,7 @@ async def context_hook(payload: Any, ctx: Any) -> None: logger = MelleaLogger.get_logger() # Emit via a plain handler so we can capture the LogRecord record = logger.makeRecord( - name="fancy_logger", + name="mellea", level=logging.INFO, fn="test", lno=0, @@ -195,7 +195,7 @@ async def visibility_hook(payload: Any, ctx: Any) -> None: logger = MelleaLogger.get_logger() # Create a log record to test context visibility record = logger.makeRecord( - name="fancy_logger", + name="mellea", level=logging.INFO, fn="test", lno=0, @@ -232,7 +232,7 @@ async def test_sampling_log_context_fields_present_on_success_record( from mellea.stdlib.components import Instruction from mellea.stdlib.sampling.base import RejectionSamplingStrategy - with caplog.at_level(logging.INFO, logger="fancy_logger"): + with caplog.at_level(logging.INFO, logger="mellea"): await RejectionSamplingStrategy(loop_budget=2).sample( Instruction("test"), context=SimpleContext(), diff --git a/test/core/test_utils_logging.py b/test/core/test_utils_logging.py index cfff8b2aa..585db0615 100644 --- a/test/core/test_utils_logging.py +++ b/test/core/test_utils_logging.py @@ -7,6 +7,7 @@ import json import logging import threading +import warnings from contextlib import contextmanager from typing import Any from unittest.mock import MagicMock, patch @@ -15,6 +16,8 @@ pytestmark = pytest.mark.unit +from logging.handlers import RotatingFileHandler + from mellea.core.utils import ( RESERVED_LOG_RECORD_ATTRS, ContextFilter, @@ -22,7 +25,10 @@ JsonFormatter, MelleaLogger, OtelTraceFilter, + RESTHandler, + _parse_bool_env, clear_log_context, + configure_logging, log_context, set_log_context, ) @@ -313,8 +319,8 @@ def test_filter_noop_when_no_context(self) -> None: class TestMelleaLoggerLogLevel: def _reset(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").setLevel(logging.NOTSET) + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").setLevel(logging.NOTSET) def teardown_method(self) -> None: self._reset() @@ -342,7 +348,7 @@ def test_invalid_level_falls_back_to_info( class TestMelleaLoggerJsonConsole: def _reset(self) -> None: MelleaLogger.logger = None - logger = logging.getLogger("fancy_logger") + logger = logging.getLogger("mellea") logger.handlers.clear() logger.setLevel(logging.NOTSET) @@ -355,8 +361,6 @@ def teardown_method(self) -> None: def _get_stream_handler(self) -> logging.StreamHandler: # type: ignore[type-arg] logger = MelleaLogger.get_logger() handlers = [h for h in logger.handlers if isinstance(h, logging.StreamHandler)] - # RESTHandler is a subclass of Handler but not StreamHandler, so this - # correctly picks the console handler. return handlers[0] def test_default_uses_custom_formatter( @@ -397,14 +401,14 @@ def test_json_console_disabled_with_false( class TestMelleaLoggerFiltersWired: def setup_method(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").setLevel(logging.NOTSET) + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").setLevel(logging.NOTSET) clear_log_context() def teardown_method(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").setLevel(logging.NOTSET) + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").setLevel(logging.NOTSET) clear_log_context() def test_context_filter_present(self) -> None: @@ -564,13 +568,13 @@ def test_reserved_set_is_non_empty(self) -> None: class TestGetLoggerThreadSafety: def setup_method(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").setLevel(logging.NOTSET) + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").setLevel(logging.NOTSET) def teardown_method(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").setLevel(logging.NOTSET) + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").setLevel(logging.NOTSET) def test_concurrent_get_logger_returns_same_instance(self) -> None: """Multiple threads calling get_logger() must all get the same object.""" @@ -705,13 +709,13 @@ def test_all_log_levels_format(self): class TestFilterFormatterIntegration: def setup_method(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").filters.clear() + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").filters.clear() def teardown_method(self) -> None: MelleaLogger.logger = None - logging.getLogger("fancy_logger").handlers.clear() - logging.getLogger("fancy_logger").filters.clear() + logging.getLogger("mellea").handlers.clear() + logging.getLogger("mellea").filters.clear() def test_json_formatter_picks_up_filter_output(self): """OtelTraceFilter + JsonFormatter round-trip injects trace context.""" @@ -783,3 +787,500 @@ def test_logger_singleton_with_otel_filter_and_custom_formatter(self): assert "logger integration test" in output finally: logger.removeHandler(handler) + + +# --------------------------------------------------------------------------- +# MELLEA_LOG_ENABLED master switch +# --------------------------------------------------------------------------- + + +@pytest.mark.unit +class TestMelleaLogEnabled: + def _reset(self) -> None: + MelleaLogger.logger = None + logger = logging.getLogger("mellea") + logger.handlers.clear() + logger.setLevel(logging.NOTSET) + + def setup_method(self) -> None: + self._reset() + + def teardown_method(self) -> None: + self._reset() + + def test_default_adds_handlers(self, monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + logger = MelleaLogger.get_logger() + assert len(logger.handlers) > 0 + + def test_enabled_true_adds_handlers(self, monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.setenv("MELLEA_LOG_ENABLED", "true") + logger = MelleaLogger.get_logger() + assert len(logger.handlers) > 0 + + def test_enabled_false_adds_no_handlers( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_ENABLED", "false") + logger = MelleaLogger.get_logger() + assert len(logger.handlers) == 0 + + def test_enabled_0_adds_no_handlers(self, monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.setenv("MELLEA_LOG_ENABLED", "0") + logger = MelleaLogger.get_logger() + assert len(logger.handlers) == 0 + + def test_enabled_no_adds_no_handlers(self, monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.setenv("MELLEA_LOG_ENABLED", "no") + logger = MelleaLogger.get_logger() + assert len(logger.handlers) == 0 + + def test_disabled_logger_still_has_filters( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_ENABLED", "false") + logger = MelleaLogger.get_logger() + assert any(isinstance(f, ContextFilter) for f in logger.filters) + assert any(isinstance(f, OtelTraceFilter) for f in logger.filters) + + +# --------------------------------------------------------------------------- +# MELLEA_LOG_CONSOLE console handler toggle +# --------------------------------------------------------------------------- + + +@pytest.mark.unit +class TestMelleaLogConsole: + def _reset(self) -> None: + MelleaLogger.logger = None + logger = logging.getLogger("mellea") + logger.handlers.clear() + logger.setLevel(logging.NOTSET) + + def setup_method(self) -> None: + self._reset() + + def teardown_method(self) -> None: + self._reset() + + def _stream_handlers(self) -> list[logging.StreamHandler]: # type: ignore[type-arg] + logger = MelleaLogger.get_logger() + return [h for h in logger.handlers if isinstance(h, logging.StreamHandler)] + + def test_default_console_enabled(self, monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.delenv("MELLEA_LOG_CONSOLE", raising=False) + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + assert len(self._stream_handlers()) >= 1 + + def test_console_false_removes_stream_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "false") + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + assert len(self._stream_handlers()) == 0 + + def test_console_0_removes_stream_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "0") + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + assert len(self._stream_handlers()) == 0 + + def test_console_no_removes_stream_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "no") + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + assert len(self._stream_handlers()) == 0 + + def test_console_true_keeps_stream_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "true") + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + assert len(self._stream_handlers()) >= 1 + + def test_no_rest_handler_when_console_disabled_and_no_webhook( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "false") + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + monkeypatch.delenv("MELLEA_LOG_WEBHOOK", raising=False) + monkeypatch.delenv("MELLEA_FLOG", raising=False) + monkeypatch.delenv("FLOG", raising=False) + logger = MelleaLogger.get_logger() + assert not any(isinstance(h, RESTHandler) for h in logger.handlers) + + +# --------------------------------------------------------------------------- +# _parse_bool_env helper +# --------------------------------------------------------------------------- + + +@pytest.mark.unit +class TestParseBoolEnv: + def test_true_values(self) -> None: + for v in ("1", "true", "yes", "TRUE", "YES", "True"): + assert _parse_bool_env(v) is True + + def test_false_values(self) -> None: + for v in ("0", "false", "no", "FALSE", "NO", "False"): + assert _parse_bool_env(v) is False + + def test_empty_uses_default_true(self) -> None: + assert _parse_bool_env("", default=True) is True + + def test_empty_uses_default_false(self) -> None: + assert _parse_bool_env("", default=False) is False + + def test_unrecognised_uses_default(self) -> None: + assert _parse_bool_env("maybe", default=True) is True + assert _parse_bool_env("maybe", default=False) is False + + def test_whitespace_stripped(self) -> None: + assert _parse_bool_env(" true ") is True + assert _parse_bool_env(" false ") is False + + +# --------------------------------------------------------------------------- +# Webhook handler (MELLEA_LOG_WEBHOOK / deprecated MELLEA_FLOG / FLOG) +# --------------------------------------------------------------------------- + + +@pytest.mark.unit +class TestWebhookHandler: + def _reset(self) -> None: + MelleaLogger.logger = None + logger = logging.getLogger("mellea") + logger.handlers.clear() + logger.setLevel(logging.NOTSET) + + def setup_method(self) -> None: + self._reset() + + def teardown_method(self) -> None: + self._reset() + + def _rest_handlers(self) -> list[RESTHandler]: + return [ + h for h in MelleaLogger.get_logger().handlers if isinstance(h, RESTHandler) + ] + + def test_no_webhook_env_means_no_rest_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.delenv("MELLEA_LOG_WEBHOOK", raising=False) + monkeypatch.delenv("MELLEA_FLOG", raising=False) + monkeypatch.delenv("FLOG", raising=False) + assert len(self._rest_handlers()) == 0 + + def test_mellea_log_webhook_attaches_rest_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_WEBHOOK", "http://example.com/logs") + monkeypatch.delenv("MELLEA_FLOG", raising=False) + monkeypatch.delenv("FLOG", raising=False) + handlers = self._rest_handlers() + assert len(handlers) == 1 + assert handlers[0].api_url == "http://example.com/logs" + + def test_mellea_flog_deprecated_still_works( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.delenv("MELLEA_LOG_WEBHOOK", raising=False) + monkeypatch.setenv("MELLEA_FLOG", "1") + monkeypatch.delenv("FLOG", raising=False) + with warnings.catch_warnings(record=True) as caught: + warnings.simplefilter("always") + handlers = self._rest_handlers() + + assert len(handlers) == 1 + assert handlers[0].api_url == "http://localhost:8000/api/receive" + assert any(issubclass(w.category, DeprecationWarning) for w in caught) + + def test_flog_deprecated_still_works(self, monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.delenv("MELLEA_LOG_WEBHOOK", raising=False) + monkeypatch.delenv("MELLEA_FLOG", raising=False) + monkeypatch.setenv("FLOG", "1") + with warnings.catch_warnings(record=True) as caught: + warnings.simplefilter("always") + handlers = self._rest_handlers() + + assert len(handlers) == 1 + assert any(issubclass(w.category, DeprecationWarning) for w in caught) + + def test_webhook_takes_precedence_over_mellea_flog( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_WEBHOOK", "http://new.example.com/hook") + monkeypatch.setenv("MELLEA_FLOG", "1") + handlers = self._rest_handlers() + assert len(handlers) == 1 + assert handlers[0].api_url == "http://new.example.com/hook" + + def test_both_mellea_flog_and_flog_set_uses_mellea_flog( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + """MELLEA_FLOG takes priority over FLOG; exactly one DeprecationWarning is issued.""" + monkeypatch.delenv("MELLEA_LOG_WEBHOOK", raising=False) + monkeypatch.setenv("MELLEA_FLOG", "1") + monkeypatch.setenv("FLOG", "1") + with warnings.catch_warnings(record=True) as caught: + warnings.simplefilter("always") + handlers = self._rest_handlers() + + assert len(handlers) == 1 + assert handlers[0].api_url == "http://localhost:8000/api/receive" + deprecation_warnings = [ + w for w in caught if issubclass(w.category, DeprecationWarning) + ] + assert len(deprecation_warnings) == 1 + assert "MELLEA_FLOG" in str(deprecation_warnings[0].message) + + def test_rest_handler_emit_sends_unconditionally( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + """RESTHandler.emit() sends without checking any env var.""" + + class _FakeResponse: + def raise_for_status(self) -> None: + pass + + with patch("mellea.core.utils.requests.request") as mock_req: + mock_req.return_value = _FakeResponse() + handler = RESTHandler("http://example.com/logs") + handler.setFormatter(JsonFormatter()) + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="ping", + args=(), + exc_info=None, + ) + handler.emit(record) + + assert mock_req.call_count == 1 + + +# --------------------------------------------------------------------------- +# configure_logging() + RotatingFileHandler +# --------------------------------------------------------------------------- + + +def _close_and_clear(lg: logging.Logger) -> None: + """Close all handlers on *lg* then remove them, preventing fd leaks.""" + for h in list(lg.handlers): + h.close() + lg.handlers.clear() + + +@pytest.mark.unit +class TestConfigureLogging: + def _reset(self) -> None: + MelleaLogger.logger = None + logger = logging.getLogger("mellea") + _close_and_clear(logger) + logger.setLevel(logging.NOTSET) + + def setup_method(self) -> None: + self._reset() + + def teardown_method(self) -> None: + self._reset() + + def _make_bare_logger(self) -> logging.Logger: + """Return a fresh logger with no handlers; caller must call _close_and_clear().""" + lg = logging.getLogger(f"test_configure_{id(self)}") + _close_and_clear(lg) + return lg + + # --- file handler presence --- + + def test_no_file_handler_when_env_unset( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.delenv("MELLEA_LOG_FILE", raising=False) + lg = self._make_bare_logger() + configure_logging(lg) + assert not any(isinstance(h, RotatingFileHandler) for h in lg.handlers) + + def test_file_handler_added_when_env_set( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + lg = self._make_bare_logger() + configure_logging(lg) + assert any(isinstance(h, RotatingFileHandler) for h in lg.handlers) + _close_and_clear(lg) + + def test_file_handler_is_rotating( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert isinstance(fh, RotatingFileHandler) + _close_and_clear(lg) + + def test_file_handler_default_max_bytes( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.delenv("MELLEA_LOG_FILE_MAX_BYTES", raising=False) + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert fh.maxBytes == 10_485_760 + _close_and_clear(lg) + + def test_file_handler_default_backup_count( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.delenv("MELLEA_LOG_FILE_BACKUP_COUNT", raising=False) + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert fh.backupCount == 5 + _close_and_clear(lg) + + def test_file_handler_custom_max_bytes( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.setenv("MELLEA_LOG_FILE_MAX_BYTES", "1048576") + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert fh.maxBytes == 1_048_576 + _close_and_clear(lg) + + def test_file_handler_custom_backup_count( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.setenv("MELLEA_LOG_FILE_BACKUP_COUNT", "3") + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert fh.backupCount == 3 + _close_and_clear(lg) + + # --- per-handler format --- + + def test_file_handler_uses_plain_formatter_by_default( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.delenv("MELLEA_LOG_JSON", raising=False) + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert not isinstance(fh.formatter, JsonFormatter) + _close_and_clear(lg) + + def test_file_handler_uses_json_formatter_when_env_set( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.setenv("MELLEA_LOG_JSON", "true") + lg = self._make_bare_logger() + configure_logging(lg) + fh = next(h for h in lg.handlers if isinstance(h, RotatingFileHandler)) + assert isinstance(fh.formatter, JsonFormatter) + _close_and_clear(lg) + + # --- error handling --- + + def test_invalid_max_bytes_warns_and_skips_file_handler( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.setenv("MELLEA_LOG_FILE_MAX_BYTES", "not-a-number") + lg = self._make_bare_logger() + with warnings.catch_warnings(record=True) as caught: + warnings.simplefilter("always") + configure_logging(lg) + + assert not any(isinstance(h, RotatingFileHandler) for h in lg.handlers) + assert any(issubclass(w.category, UserWarning) for w in caught) + + def test_invalid_backup_count_warns_and_skips_file_handler( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.setenv("MELLEA_LOG_FILE_BACKUP_COUNT", "not-a-number") + lg = self._make_bare_logger() + with warnings.catch_warnings(record=True) as caught: + warnings.simplefilter("always") + configure_logging(lg) + + assert not any(isinstance(h, RotatingFileHandler) for h in lg.handlers) + assert any(issubclass(w.category, UserWarning) for w in caught) + + def test_unwritable_path_warns_and_skips_file_handler( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.setenv("MELLEA_LOG_FILE", "/no/such/directory/mellea.log") + lg = self._make_bare_logger() + with warnings.catch_warnings(record=True) as caught: + warnings.simplefilter("always") + configure_logging(lg) + + assert not any(isinstance(h, RotatingFileHandler) for h in lg.handlers) + assert any(issubclass(w.category, UserWarning) for w in caught) + + # --- multiple handlers simultaneously --- + + def test_multiple_handlers_active_simultaneously( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "mellea.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + monkeypatch.setenv("MELLEA_LOG_WEBHOOK", "http://example.com/logs") + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "true") + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + lg = self._make_bare_logger() + configure_logging(lg) + has_stream = any(isinstance(h, logging.StreamHandler) for h in lg.handlers) + has_file = any(isinstance(h, RotatingFileHandler) for h in lg.handlers) + has_rest = any(isinstance(h, RESTHandler) for h in lg.handlers) + assert has_stream and has_file and has_rest + _close_and_clear(lg) + + def test_configure_logging_twice_doubles_handlers( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + """Calling configure_logging twice always appends — documented non-idempotent behaviour.""" + monkeypatch.delenv("MELLEA_LOG_FILE", raising=False) + monkeypatch.delenv("MELLEA_LOG_ENABLED", raising=False) + monkeypatch.setenv("MELLEA_LOG_CONSOLE", "true") + lg = self._make_bare_logger() + configure_logging(lg) + configure_logging(lg) + stream_handlers = [h for h in lg.handlers if type(h) is logging.StreamHandler] + assert len(stream_handlers) == 2 + + # --- configure_logging called from get_logger --- + + def test_get_logger_delegates_to_configure_logging( + self, monkeypatch: pytest.MonkeyPatch, tmp_path: Any + ) -> None: + log_path = str(tmp_path / "via_get_logger.log") + monkeypatch.setenv("MELLEA_LOG_FILE", log_path) + logger = MelleaLogger.get_logger() + assert any(isinstance(h, RotatingFileHandler) for h in logger.handlers) diff --git a/test/telemetry/test_logging.py b/test/telemetry/test_logging.py index b8cddbce8..c95579b90 100644 --- a/test/telemetry/test_logging.py +++ b/test/telemetry/test_logging.py @@ -1,7 +1,9 @@ """Unit tests for OpenTelemetry logging instrumentation.""" +import importlib +import logging import os -from unittest.mock import MagicMock, patch +from unittest.mock import MagicMock, call, patch import pytest @@ -22,15 +24,12 @@ def _reset_logging_modules(): """Helper to reset logging state and reload modules.""" - import importlib - import logging - import mellea.core.utils import mellea.telemetry.logging from mellea.core.utils import MelleaLogger # Clear any existing handlers from previous tests - fancy_logger = logging.getLogger("fancy_logger") + fancy_logger = logging.getLogger("mellea") fancy_logger.handlers.clear() # Reset MelleaLogger singleton @@ -44,7 +43,7 @@ def _reset_logging_modules(): @pytest.fixture def clean_logging_env(monkeypatch): """Clean logging environment variables before each test.""" - monkeypatch.delenv("MELLEA_LOGS_OTLP", raising=False) + monkeypatch.delenv("MELLEA_LOG_OTLP", raising=False) monkeypatch.delenv("OTEL_EXPORTER_OTLP_ENDPOINT", raising=False) monkeypatch.delenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT", raising=False) monkeypatch.delenv("OTEL_SERVICE_NAME", raising=False) @@ -57,7 +56,7 @@ def clean_logging_env(monkeypatch): @pytest.fixture def enable_otlp_logging(monkeypatch): """Enable OTLP logging with endpoint for tests.""" - monkeypatch.setenv("MELLEA_LOGS_OTLP", "true") + monkeypatch.setenv("MELLEA_LOG_OTLP", "true") monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "http://localhost:4317") _reset_logging_modules() @@ -86,20 +85,17 @@ def test_otlp_logging_enabled_with_env_var(enable_otlp_logging): def test_otlp_logging_enabled_without_endpoint_warns(monkeypatch, clean_logging_env): - """Test that enabling OTLP without endpoint produces warning.""" - monkeypatch.setenv("MELLEA_LOGS_OTLP", "true") + """Test that enabling OTLP without endpoint produces warning on first handler request.""" + monkeypatch.setenv("MELLEA_LOG_OTLP", "true") # No endpoint set - import importlib + _reset_logging_modules() - import mellea.telemetry.logging + from mellea.telemetry.logging import get_otlp_log_handler with pytest.warns(UserWarning, match="no endpoint is configured"): - importlib.reload(mellea.telemetry.logging) - - from mellea.telemetry.logging import get_otlp_log_handler + handler = get_otlp_log_handler() - handler = get_otlp_log_handler() assert handler is None @@ -108,9 +104,7 @@ def test_otlp_logging_with_various_truthy_values(monkeypatch, clean_logging_env) monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "http://localhost:4317") for value in ["true", "True", "TRUE", "1", "yes", "Yes", "YES"]: - monkeypatch.setenv("MELLEA_LOGS_OTLP", value) - - import importlib + monkeypatch.setenv("MELLEA_LOG_OTLP", value) import mellea.telemetry.logging @@ -123,19 +117,21 @@ def test_otlp_logging_with_various_truthy_values(monkeypatch, clean_logging_env) def test_logs_specific_endpoint_takes_precedence(monkeypatch, clean_logging_env): - """Test that OTEL_EXPORTER_OTLP_LOGS_ENDPOINT takes precedence.""" - monkeypatch.setenv("MELLEA_LOGS_OTLP", "true") + """Test that OTEL_EXPORTER_OTLP_LOGS_ENDPOINT takes precedence over the general endpoint.""" + monkeypatch.setenv("MELLEA_LOG_OTLP", "true") monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "http://localhost:4317") monkeypatch.setenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT", "http://localhost:4318/logs") - import importlib + _reset_logging_modules() import mellea.telemetry.logging - importlib.reload(mellea.telemetry.logging) - - # Verify the logs-specific endpoint is used - assert mellea.telemetry.logging._OTLP_LOGS_ENDPOINT == "http://localhost:4318/logs" + with patch( + "mellea.telemetry.logging.OTLPLogExporter", wraps=OTLPLogExporter + ) as mock_exporter: + mellea.telemetry.logging.get_otlp_log_handler() + # The logs-specific endpoint must be passed to the exporter, not the general one + assert mock_exporter.call_args == call(endpoint="http://localhost:4318/logs") # Handler Integration Tests @@ -143,8 +139,6 @@ def test_logs_specific_endpoint_takes_precedence(monkeypatch, clean_logging_env) def test_get_otlp_log_handler_can_be_added_to_logger(enable_otlp_logging): """Test that OTLP handler can be added to a Python logger.""" - import logging - from mellea.telemetry.logging import get_otlp_log_handler logger = logging.getLogger("test_logger") @@ -183,8 +177,8 @@ def test_fancy_logger_works_without_otlp(clean_logging_env): logger = MelleaLogger.get_logger() - # Should still have REST and console handlers - assert len(logger.handlers) >= 2 + # Should still have at least a console handler + assert len(logger.handlers) >= 1 # Should not have OTLP handler has_otlp_handler = any(isinstance(h, LoggingHandler) for h in logger.handlers) # type: ignore From 1ed14980c3a84e0792f6f2768139473b34bb9df2 Mon Sep 17 00:00:00 2001 From: AngeloDanducci Date: Fri, 24 Apr 2026 00:23:53 -0400 Subject: [PATCH 2/2] address feedback from jake --- docs/docs/observability/logging.md | 30 +++++++++++++++++++--------- docs/docs/observability/telemetry.md | 2 +- mellea/core/utils.py | 17 +++++++++++++--- mellea/telemetry/__init__.py | 2 +- mellea/telemetry/logging.py | 8 ++++---- test/telemetry/test_logging.py | 6 +++--- 6 files changed, 44 insertions(+), 21 deletions(-) diff --git a/docs/docs/observability/logging.md b/docs/docs/observability/logging.md index b78dfa298..903b2e56a 100644 --- a/docs/docs/observability/logging.md +++ b/docs/docs/observability/logging.md @@ -22,9 +22,21 @@ Mellea uses `MelleaLogger`, a color-coded singleton logger built on Python's | Variable | Description | Default | | -------- | ----------- | ------- | +| `MELLEA_LOG_ENABLED` | Master switch. Set to `false` / `0` / `no` to suppress all handlers (useful in test environments) | `true` | | `MELLEA_LOG_LEVEL` | Log level name (e.g. `DEBUG`, `INFO`, `WARNING`) | `INFO` | | `MELLEA_LOG_JSON` | Set to any truthy value (`1`, `true`, `yes`) to emit structured JSON instead of colour-coded output | unset | -| `MELLEA_FLOG` | Set to any value to forward logs to a local REST endpoint at `http://localhost:8000/api/receive` | unset | +| `MELLEA_LOG_CONSOLE` | Set to `false` / `0` / `no` to disable the console (stdout) handler | `true` | +| `MELLEA_LOG_FILE` | Absolute or relative path for rotating file output (e.g. `/var/log/mellea.log`). When unset no file handler is attached | unset | +| `MELLEA_LOG_FILE_MAX_BYTES` | Maximum size in bytes before the log file is rotated | `10485760` (10 MB) | +| `MELLEA_LOG_FILE_BACKUP_COUNT` | Number of rotated backup files to keep | `5` | +| `MELLEA_LOG_OTLP` | Set to `true` / `1` / `yes` to export logs via OTLP. Requires `opentelemetry-sdk` and a configured OTLP endpoint | `false` | +| `MELLEA_LOG_WEBHOOK` | HTTP(S) URL to forward log records to via HTTP POST. Supersedes the deprecated `MELLEA_FLOG` and `FLOG` variables | unset | +| `MELLEA_FLOG` | **Deprecated.** Activates a webhook handler pointed at `http://localhost:8000/api/receive`. Use `MELLEA_LOG_WEBHOOK` instead | unset | + +> **Note:** If `MELLEA_LOG_FILE` is set but the path cannot be opened (for +> example due to a permissions error or an invalid path), Mellea emits a +> `UserWarning` and continues without file logging. The application is never +> crashed by a misconfigured log path. By default, `MelleaLogger` logs at `INFO` level with color-coded output to stdout. Set `MELLEA_LOG_LEVEL` to change the level: @@ -112,11 +124,11 @@ logs from distributed services. ### Enable OTLP logging ```bash -export MELLEA_LOGS_OTLP=true +export MELLEA_LOG_OTLP=true export OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 -# Optional: logs-specific endpoint (overrides general endpoint) -export OTEL_EXPORTER_OTLP_LOGS_ENDPOINT=http://localhost:4318 +# Optional: log-specific endpoint (overrides general endpoint) +export OTEL_EXPORTER_OTLP_LOG_ENDPOINT=http://localhost:4318 # Optional: set service name export OTEL_SERVICE_NAME=my-mellea-app @@ -124,11 +136,11 @@ export OTEL_SERVICE_NAME=my-mellea-app ### How it works -When `MELLEA_LOGS_OTLP=true`, `MelleaLogger` adds an OpenTelemetry +When `MELLEA_LOG_OTLP=true`, `MelleaLogger` adds an OpenTelemetry `LoggingHandler` alongside its existing handlers: - **Console handler** — continues to work normally (color-coded output) -- **REST handler** — continues to work normally (when `MELLEA_FLOG` is set) +- **REST handler** — continues to work normally (when `MELLEA_LOG_WEBHOOK` is set) - **OTLP handler** — exports logs to the configured OTLP collector Logs are exported using OpenTelemetry's Logs API with batched processing @@ -204,9 +216,9 @@ OTLP logs work with any OTLP-compatible platform: **Logs not appearing in OTLP collector:** -1. Verify `MELLEA_LOGS_OTLP=true` is set. +1. Verify `MELLEA_LOG_OTLP=true` is set. 2. Check that an OTLP endpoint is configured - (`OTEL_EXPORTER_OTLP_ENDPOINT` or `OTEL_EXPORTER_OTLP_LOGS_ENDPOINT`). + (`OTEL_EXPORTER_OTLP_ENDPOINT` or `OTEL_EXPORTER_OTLP_LOG_ENDPOINT`). 3. Verify the OTLP collector is running and configured to receive logs. 4. Check collector logs for connection errors. @@ -216,7 +228,7 @@ OTLP logs work with any OTLP-compatible platform: WARNING: OTLP logs exporter is enabled but no endpoint is configured ``` -Set either `OTEL_EXPORTER_OTLP_ENDPOINT` or `OTEL_EXPORTER_OTLP_LOGS_ENDPOINT`. +Set either `OTEL_EXPORTER_OTLP_ENDPOINT` or `OTEL_EXPORTER_OTLP_LOG_ENDPOINT`. **Connection refused:** diff --git a/docs/docs/observability/telemetry.md b/docs/docs/observability/telemetry.md index bd461e556..9c60f254e 100644 --- a/docs/docs/observability/telemetry.md +++ b/docs/docs/observability/telemetry.md @@ -51,7 +51,7 @@ All telemetry is configured via environment variables: | Variable | Description | Default | | -------- | ----------- | ------- | | `MELLEA_LOGS_OTLP` | Enable OTLP logs exporter | `false` | -| `OTEL_EXPORTER_OTLP_LOGS_ENDPOINT` | Logs-specific OTLP endpoint (overrides general) | none | +| `OTEL_EXPORTER_OTLP_LOG_ENDPOINT` | Logs-specific OTLP endpoint (overrides general) | none | ## Quick start diff --git a/mellea/core/utils.py b/mellea/core/utils.py index d18800c9c..ebfee87b1 100644 --- a/mellea/core/utils.py +++ b/mellea/core/utils.py @@ -33,7 +33,7 @@ ``MELLEA_LOG_OTLP`` Set to ``true`` / ``1`` / ``yes`` to export logs via OpenTelemetry Logs Protocol. Requires ``opentelemetry-sdk`` and an OTLP endpoint configured - via ``OTEL_EXPORTER_OTLP_LOGS_ENDPOINT`` or ``OTEL_EXPORTER_OTLP_ENDPOINT``. + via ``OTEL_EXPORTER_OTLP_LOG_ENDPOINT`` or ``OTEL_EXPORTER_OTLP_ENDPOINT``. ``MELLEA_LOG_WEBHOOK`` HTTP(S) URL to forward log records to via HTTP POST. When set a :class:`RESTHandler` is attached. Supersedes the deprecated ``MELLEA_FLOG`` @@ -556,12 +556,20 @@ def configure_logging(logger: logging.Logger) -> None: """Attach log handlers to *logger* based on current environment variables. It always appends new handlers (the caller is responsible for clearing - existing ones before re-configuring). It is called automatically by - :meth:`MelleaLogger.get_logger` and is also available for programmatic use. + existing ones before re-configuring). It is invoked automatically on the + first call to :meth:`MelleaLogger.get_logger`; subsequent calls return the + same singleton logger with its handlers already in place. It is also + available for programmatic use when you need to attach handlers to a custom + logger. When ``MELLEA_LOG_ENABLED`` is falsy no handlers are attached; the logger still exists and accepts records, but they are silently discarded. + If ``MELLEA_LOG_FILE`` is set but the path cannot be opened (e.g. due to a + permissions error), a :class:`UserWarning` is emitted and file logging is + skipped. The remaining handlers are still attached and the application + continues normally. + Args: logger: The :class:`logging.Logger` to configure. """ @@ -606,6 +614,9 @@ def configure_logging(logger: logging.Logger) -> None: ) logger.addHandler(file_handler) except (ValueError, OSError) as exc: + # Emit a warning rather than raising so a misconfigured log path + # never crashes the application. The rest of the handlers still + # work; only file logging is lost. warnings.warn( f"Failed to configure file logging handler for {log_file!r}: {exc}. " "File logging will be skipped.", diff --git a/mellea/telemetry/__init__.py b/mellea/telemetry/__init__.py index d392baa36..85c9f29fa 100644 --- a/mellea/telemetry/__init__.py +++ b/mellea/telemetry/__init__.py @@ -34,7 +34,7 @@ Logging: - MELLEA_LOG_OTLP: Enable OTLP log export (default: false) - - OTEL_EXPORTER_OTLP_LOGS_ENDPOINT: Logs-specific endpoint (optional) + - OTEL_EXPORTER_OTLP_LOG_ENDPOINT: Logs-specific endpoint (optional) - OTEL_EXPORTER_OTLP_ENDPOINT: General OTLP endpoint (fallback) - OTEL_SERVICE_NAME: Service name for logs (default: mellea) diff --git a/mellea/telemetry/logging.py b/mellea/telemetry/logging.py index 12b7615ab..fbae1520c 100644 --- a/mellea/telemetry/logging.py +++ b/mellea/telemetry/logging.py @@ -3,8 +3,8 @@ Provides log export using OpenTelemetry Logs API with OTLP exporter support. Configuration via environment variables: -- MELLEA_LOG_OTLP: Enable OTLP logs exporter (default: false) -- OTEL_EXPORTER_OTLP_LOGS_ENDPOINT: Logs-specific endpoint (optional, overrides general) +- MELLEA_LOG_OTLP: Enable OTLP log exporter (default: false) +- OTEL_EXPORTER_OTLP_LOG_ENDPOINT: Log-specific endpoint (optional, overrides general) - OTEL_EXPORTER_OTLP_ENDPOINT: General endpoint for all signals (fallback) - OTEL_SERVICE_NAME: Service name for logs (default: mellea) @@ -53,13 +53,13 @@ def _setup_logger_provider() -> Any: if not _OTEL_AVAILABLE: return None - endpoint = os.getenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT") or os.getenv( + endpoint = os.getenv("OTEL_EXPORTER_OTLP_LOG_ENDPOINT") or os.getenv( "OTEL_EXPORTER_OTLP_ENDPOINT" ) if not endpoint: warnings.warn( "OTLP logs exporter is enabled (MELLEA_LOG_OTLP=true) but no endpoint is configured. " - "Set OTEL_EXPORTER_OTLP_LOGS_ENDPOINT or OTEL_EXPORTER_OTLP_ENDPOINT to export logs.", + "Set OTEL_EXPORTER_OTLP_LOG_ENDPOINT or OTEL_EXPORTER_OTLP_ENDPOINT to export logs.", UserWarning, stacklevel=3, ) diff --git a/test/telemetry/test_logging.py b/test/telemetry/test_logging.py index c95579b90..25f3c72fa 100644 --- a/test/telemetry/test_logging.py +++ b/test/telemetry/test_logging.py @@ -45,7 +45,7 @@ def clean_logging_env(monkeypatch): """Clean logging environment variables before each test.""" monkeypatch.delenv("MELLEA_LOG_OTLP", raising=False) monkeypatch.delenv("OTEL_EXPORTER_OTLP_ENDPOINT", raising=False) - monkeypatch.delenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT", raising=False) + monkeypatch.delenv("OTEL_EXPORTER_OTLP_LOG_ENDPOINT", raising=False) monkeypatch.delenv("OTEL_SERVICE_NAME", raising=False) _reset_logging_modules() @@ -117,10 +117,10 @@ def test_otlp_logging_with_various_truthy_values(monkeypatch, clean_logging_env) def test_logs_specific_endpoint_takes_precedence(monkeypatch, clean_logging_env): - """Test that OTEL_EXPORTER_OTLP_LOGS_ENDPOINT takes precedence over the general endpoint.""" + """Test that OTEL_EXPORTER_OTLP_LOG_ENDPOINT takes precedence over the general endpoint.""" monkeypatch.setenv("MELLEA_LOG_OTLP", "true") monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "http://localhost:4317") - monkeypatch.setenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT", "http://localhost:4318/logs") + monkeypatch.setenv("OTEL_EXPORTER_OTLP_LOG_ENDPOINT", "http://localhost:4318/logs") _reset_logging_modules()