chore: import upstream snapshot with attribution

tests/test_logging.py

@@ -0,0 +1,422 @@
+# Copyright (c) Microsoft. All rights reserved.
+
+from __future__ import annotations
+
+import io
+import logging
+import multiprocessing as mp
+from multiprocessing.queues import Queue
+from pathlib import Path
+from typing import Any, Dict, List
+
+import pytest
+
+from agentlightning.logging import _to_level_value  # pyright: ignore[reportPrivateUsage]
+from agentlightning.logging import (
+    DATE_FORMAT,
+    DEFAULT_FORMAT,
+)
+
+pytestmark = pytest.mark.utils
+
+
+def _logging_worker(case: str, queue: Queue[Dict[str, Any]]) -> None:
+    """
+    Runs in a separate process using spawn. It performs a specific logging
+    configuration scenario and returns a summary dict via the queue.
+    """
+    import logging
+    import warnings
+
+    # Re-import inside the subprocess so everything is picklable & isolated
+    from agentlightning.logging import (
+        setup,
+        setup_module,
+    )
+
+    if case == "setup_module_plain_console":
+        logger = setup_module(
+            level="DEBUG",
+            name="agentlightning.test",
+            console=True,
+            color=False,
+            propagate=False,
+        )
+
+        handlers = logger.handlers
+        handler = handlers[0] if handlers else None
+        fmt = handler.formatter._fmt if handler and handler.formatter else None
+        datefmt = handler.formatter.datefmt if handler and handler.formatter else None
+
+        queue.put(
+            {
+                "logger_name": logger.name,
+                "logger_level": logger.level,
+                "num_handlers": len(handlers),
+                "handler_class": handler.__class__.__name__ if handler else None,
+                "handler_level": handler.level if handler else None,
+                "fmt": fmt,
+                "datefmt": datefmt,
+            }
+        )
+
+    elif case == "setup_module_color_rich":
+        # Rich variant: color=True uses RichHandler
+        logger = setup_module(
+            level="INFO",
+            name="agentlightning.rich",
+            console=True,
+            color=True,
+            propagate=False,
+        )
+        handlers = logger.handlers
+        handler = handlers[0] if handlers else None
+
+        queue.put(
+            {
+                "logger_name": logger.name,
+                "logger_level": logger.level,
+                "num_handlers": len(handlers),
+                "handler_class": handler.__class__.__name__ if handler else None,
+                "handler_has_formatter": handler.formatter is not None if handler else None,
+            }
+        )
+
+    elif case == "setup_with_submodules_apply_to_capture_warnings":
+        # Extra handler to attach via extra_handlers
+        stream = io.StringIO()
+        stream_handler = logging.StreamHandler(stream)
+
+        setup(
+            level="INFO",
+            console=False,
+            color=False,
+            propagate=False,
+            disable_existing_loggers=False,
+            capture_warnings=True,
+            submodule_levels={"agentlightning.io": "DEBUG"},
+            extra_handlers=[stream_handler],
+            apply_to=["external"],
+        )
+
+        base = logging.getLogger("agentlightning")
+        sub = logging.getLogger("agentlightning.io")
+        ext = logging.getLogger("external")
+
+        # Capture warnings via logging after capture_warnings=True
+        class ListHandler(logging.Handler):
+            def __init__(self) -> None:
+                super().__init__()
+                self.records: List[logging.LogRecord] = []
+
+            def emit(self, record: logging.LogRecord) -> None:
+                self.records.append(record)
+
+        lh = ListHandler()
+        wlog = logging.getLogger("py.warnings")
+        wlog.handlers.clear()
+        wlog.addHandler(lh)
+        wlog.setLevel(logging.WARNING)
+        wlog.propagate = False
+
+        warnings.warn("from warnings", UserWarning)
+
+        queue.put(
+            {
+                "base_level": base.level,
+                "base_num_handlers": len(base.handlers),
+                "extra_in_base": stream_handler in base.handlers,
+                "sub_level": sub.level,
+                "ext_level": ext.level,
+                "ext_handlers_same": base.handlers == ext.handlers,
+                "ext_propagate": ext.propagate,
+                "warnings_logged": len(lh.records),
+            }
+        )
+
+    elif case == "setup_with_console_and_extra_handler":
+        # Console + extra handler combination to test handler attachment
+        stream = io.StringIO()
+        extra_handler = logging.StreamHandler(stream)
+
+        setup(
+            level="WARNING",
+            console=True,
+            color=False,
+            propagate=False,
+            extra_handlers=[extra_handler],
+        )
+
+        base = logging.getLogger("agentlightning")
+        handler_classes = [h.__class__.__name__ for h in base.handlers]
+        has_extra = extra_handler in base.handlers
+
+        queue.put(
+            {
+                "base_level": base.level,
+                "num_handlers": len(base.handlers),
+                "handler_classes": handler_classes,
+                "has_extra": has_extra,
+            }
+        )
+
+    else:
+        queue.put({})
+
+
+def _logging_worker_files_string(queue: Queue[Dict[str, Any]], base_dir: str) -> None:
+    """
+    Runs in a separate spawned process and configures logging with a single
+    files=str path. Returns information about the attached FileHandler.
+    """
+    import logging
+    import os
+
+    from agentlightning.logging import setup
+
+    log_path = os.path.join(base_dir, "logs", "agent.log")
+
+    setup(
+        level="INFO",
+        console=False,
+        color=False,
+        propagate=False,
+        files=log_path,
+    )
+
+    base = logging.getLogger("agentlightning")
+    file_handlers = [h for h in base.handlers if isinstance(h, logging.FileHandler)]
+    fh = file_handlers[0] if file_handlers else None
+
+    fmt = fh.formatter._fmt if fh and fh.formatter else None
+    datefmt = fh.formatter.datefmt if fh and fh.formatter else None
+
+    queue.put(
+        {
+            "logger_level": base.level,
+            "num_handlers": len(base.handlers),
+            "num_file_handlers": len(file_handlers),
+            "file_base": fh.baseFilename if fh else None,
+            "file_level": fh.level if fh else None,
+            "fmt": fmt,
+            "datefmt": datefmt,
+        }
+    )
+
+
+def _logging_worker_files_mapping(queue: Queue[Dict[str, Any]], base_dir: str) -> None:
+    """
+    Runs in a separate spawned process and configures logging with a files=dict
+    mapping, then calls setup twice to verify idempotent FileHandler attachment.
+    """
+    import logging
+    import os
+
+    from agentlightning.logging import setup
+
+    base_log = os.path.join(base_dir, "agent.log")
+    external_log = os.path.join(base_dir, "external.log")
+
+    files_mapping: Dict[str, str] = {
+        "agentlightning": base_log,
+        "external": external_log,
+    }
+
+    def file_handlers(logger: logging.Logger) -> list[logging.FileHandler]:
+        return [h for h in logger.handlers if isinstance(h, logging.FileHandler)]
+
+    # First setup call
+    setup(
+        level="DEBUG",
+        console=False,
+        color=False,
+        propagate=False,
+        files=files_mapping,
+    )
+
+    base_logger = logging.getLogger("agentlightning")
+    ext_logger = logging.getLogger("external")
+
+    base_fh_first = file_handlers(base_logger)
+    ext_fh_first = file_handlers(ext_logger)
+
+    # Second setup call with the same mapping should not add duplicate FileHandlers
+    setup(
+        level="DEBUG",
+        console=False,
+        color=False,
+        propagate=False,
+        files=files_mapping,
+    )
+
+    base_fh_second = file_handlers(base_logger)
+    ext_fh_second = file_handlers(ext_logger)
+
+    queue.put(
+        {
+            "base_level": base_logger.level,
+            "ext_level": ext_logger.getEffectiveLevel(),
+            "base_first_count": len(base_fh_first),
+            "ext_first_count": len(ext_fh_first),
+            "base_second_count": len(base_fh_second),
+            "ext_second_count": len(ext_fh_second),
+            "base_file_first": base_fh_first[0].baseFilename if base_fh_first else None,
+            "ext_file_first": ext_fh_first[0].baseFilename if ext_fh_first else None,
+            "base_file_second": base_fh_second[0].baseFilename if base_fh_second else None,
+            "ext_file_second": ext_fh_second[0].baseFilename if ext_fh_second else None,
+            # For sanity: capture handler levels as well
+            "base_handler_level": base_fh_first[0].level if base_fh_first else None,
+            "ext_handler_level": ext_fh_first[0].level if ext_fh_first else None,
+        }
+    )
+
+
+def _run_case(case: str) -> Dict[str, Any]:
+    """Helper to run a scenario in a spawn’ed process and fetch the result."""
+    ctx = mp.get_context("spawn")
+    q: Queue[Dict[str, Any]] = ctx.Queue()
+    p = ctx.Process(target=_logging_worker, args=(case, q))
+    p.start()
+    result = q.get(timeout=10)
+    p.join(timeout=10)
+    assert p.exitcode == 0
+    return result
+
+
+def test_to_level_value_int_and_str() -> None:
+    # direct, no multiprocessing needed
+    assert _to_level_value(logging.DEBUG) == logging.DEBUG
+    assert _to_level_value("info") == logging.INFO
+    assert _to_level_value("WARNING") == logging.WARNING
+
+    with pytest.raises(ValueError):
+        _to_level_value("not-a-level")
+
+
+def test_setup_module_plain_console_spawn() -> None:
+    result = _run_case("setup_module_plain_console")
+
+    assert result["logger_name"] == "agentlightning.test"
+    assert result["logger_level"] == logging.DEBUG
+
+    # Console handler with plain formatter configured
+    assert result["num_handlers"] == 1
+    assert result["handler_class"].endswith("StreamHandler")
+    assert result["handler_level"] == logging.DEBUG
+    assert result["fmt"] == DEFAULT_FORMAT
+    assert result["datefmt"] == DATE_FORMAT
+
+
+def test_setup_module_color_rich_spawn() -> None:
+    # Only run this test if rich is installed
+    pytest.importorskip("rich")
+
+    result = _run_case("setup_module_color_rich")
+
+    assert result["logger_name"] == "agentlightning.rich"
+    assert result["logger_level"] == logging.INFO
+    assert result["num_handlers"] == 1
+    # We can’t rely on full module path, just the class name
+    assert result["handler_class"].endswith("RichHandler")
+
+
+def test_setup_with_submodules_apply_to_and_capture_warnings_spawn() -> None:
+    result = _run_case("setup_with_submodules_apply_to_capture_warnings")
+
+    # Base logger level and handler attachment
+    assert result["base_level"] == logging.INFO
+    assert result["base_num_handlers"] >= 1
+    assert result["extra_in_base"] is True
+
+    # Submodule level overridden
+    assert result["sub_level"] == logging.DEBUG
+
+    # apply_to logger mirrors base handlers & level, propagation disabled
+    assert result["ext_level"] == logging.INFO
+    assert result["ext_handlers_same"] is True
+    assert result["ext_propagate"] is False
+
+    # capture_warnings=True causes warnings.warn to go through logging
+    assert result["warnings_logged"] >= 1
+
+
+def test_setup_with_console_and_extra_handler_spawn() -> None:
+    result = _run_case("setup_with_console_and_extra_handler")
+
+    # Level propagated to base logger
+    assert result["base_level"] == logging.WARNING
+
+    # Both console handler and extra handler should be attached
+    assert result["num_handlers"] >= 2
+    assert any(cls.endswith("StreamHandler") for cls in result["handler_classes"])
+    assert result["has_extra"] is True
+
+
+def test_setup_files_string_spawn(tmp_path: Path) -> None:
+    """
+    Verifies that passing files as a string attaches a single FileHandler with
+    the expected level and default formatter in a spawned process.
+    """
+    ctx = mp.get_context("spawn")
+    q: Queue[Dict[str, Any]] = ctx.Queue()
+    p = ctx.Process(target=_logging_worker_files_string, args=(q, str(tmp_path)))
+    p.start()
+    result = q.get(timeout=10)
+    p.join(timeout=10)
+    assert p.exitcode == 0
+
+    assert result["logger_level"] == logging.INFO
+    # We expect at least one handler and exactly one FileHandler
+    assert result["num_handlers"] >= 1
+    assert result["num_file_handlers"] == 1
+
+    # Filename should be inside the tmp_path tree
+    assert str(tmp_path) in result["file_base"]
+    # FileHandler uses the base logger level
+    assert result["file_level"] == logging.INFO
+
+    # Default formatter applied by _ensure_file_handler
+    assert result["fmt"] == DEFAULT_FORMAT
+    assert result["datefmt"] == DATE_FORMAT
+
+
+def test_setup_files_mapping_spawn(tmp_path: Path) -> None:
+    """
+    Verifies that passing files as a mapping attaches FileHandlers to each
+    logger and that calling setup twice does not create duplicate handlers.
+    """
+    ctx = mp.get_context("spawn")
+    q: Queue[Dict[str, Any]] = ctx.Queue()
+    p = ctx.Process(target=_logging_worker_files_mapping, args=(q, str(tmp_path)))
+    p.start()
+    result = q.get(timeout=10)
+    p.join(timeout=10)
+    assert p.exitcode == 0
+
+    # Base logger level is DEBUG
+    assert result["base_level"] == logging.DEBUG
+
+    # External's effective level is WARNING (inherited from root)
+    assert result["ext_level"] == logging.WARNING
+
+    # First setup: one FileHandler per logger
+    assert result["base_first_count"] == 1
+    assert result["ext_first_count"] == 1
+
+    # Second setup: still one FileHandler per logger (idempotence)
+    assert result["base_second_count"] == 1
+    assert result["ext_second_count"] == 1
+
+    # File paths are stable across calls
+    assert result["base_file_first"] == result["base_file_second"]
+    assert result["ext_file_first"] == result["ext_file_second"]
+
+    # Paths should live under tmp_path
+    assert str(tmp_path) in result["base_file_first"]
+    assert str(tmp_path) in result["ext_file_first"]
+
+    # Handler levels:
+    # - base handler uses the base logger level (DEBUG)
+    # - external handler uses external's effective level at creation (WARNING)
+    assert result["base_handler_level"] == logging.DEBUG
+    assert result["ext_handler_level"] == logging.WARNING