portfolio-optimiser/tests/test_demo_stderr_quiet_loadbearing.py

"""P4 pkt. 2 — the demo's round-cap notice is damped, and the damping is NARROW by construction.

Measured on 2026-08-09, the demo wrote six stderr lines: two ``ExperimentalWarning``s from
``agent_framework`` (import time), two ``GroupChatOrchestrator reached max_rounds=3; forcing
completion.`` notices (``logging``, reaching stderr via ``logging.lastResort``), a blank line, and
the deliberately non-deterministic ``arbeidskopi:`` line.

**Only the round-cap notices are damped, and this file only tests those.** The two import-time
warnings fire while ``portfolio_optimiser/__init__.py`` imports ``run`` — always before
``simulation``'s own imports, under both invocation forms — so damping them would mean filtering
warnings inside the library package on every consumer's behalf. They are pinned in pkt. 3 instead.
Measured, not assumed: see the decision recorded at the top of ``simulation.py``.

**Why narrowness is the property under test, not the silence.** Plan P4 pkt. 3 pins stderr to a
byte-fasit so a new warning after a MAF bump or a subtree pull TRIPS the pin. A damping keyed on the
logger rather than the message would swallow that new warning too, leaving a pin that can no longer
fail for the reason it exists. So the drop-assert here is paired with a control proving an
unmeasured message from the very same logger still gets through — a filter that can only ever say
"drop" proves nothing.
"""

from __future__ import annotations

import logging
import subprocess
import sys

from portfolio_optimiser.simulation import ROUND_CAP_LOGGER, quiet_expected_round_cap_notice

_REAL_ROUND_CAP_MESSAGE = "GroupChatOrchestrator reached max_rounds=3; forcing completion."


class _Recorder(logging.Handler):
    """Collects whatever survives the logger's own filters."""

    def __init__(self) -> None:
        super().__init__()
        self.messages: list[str] = []

    def emit(self, record: logging.LogRecord) -> None:
        self.messages.append(record.getMessage())


def _record_through_real_logger(message: str, *, quiet: bool) -> list[str]:
    """Log ``message`` through the REAL emitting logger and return what reached a handler.

    Logger-level filters run in ``Logger.handle`` BEFORE ``callHandlers``, so a dropped record never
    reaches the recorder — the same point at which ``logging.lastResort`` would otherwise have
    written it to stderr in the demo process.
    """
    logger = logging.getLogger(ROUND_CAP_LOGGER)
    recorder = _Recorder()
    logger.addHandler(recorder)
    installed: logging.Filter | None = None
    try:
        if quiet:
            installed = quiet_expected_round_cap_notice()
        logger.warning("%s", message)
    finally:
        logger.removeHandler(recorder)
        if installed is not None:
            logger.removeFilter(installed)
    return recorder.messages


def test_round_cap_notice_reaches_stderr_without_the_damping() -> None:
    """T-P4.2a (the RED-proof for the test itself): the notice really is emitted through this
    logger name. The negative assert below is worthless unless the event provably happens first."""
    assert _record_through_real_logger(_REAL_ROUND_CAP_MESSAGE, quiet=False) == [
        _REAL_ROUND_CAP_MESSAGE
    ]


def test_round_cap_notice_is_dropped_by_the_damping() -> None:
    """T-P4.2b: with the damping installed, the expected round-cap notice never reaches a handler."""
    assert _record_through_real_logger(_REAL_ROUND_CAP_MESSAGE, quiet=True) == []


def test_unrelated_warning_from_the_same_logger_still_surfaces() -> None:
    """T-P4.2c (control): the damping is keyed on the message, not on the logger. A different
    warning from the very same logger still gets through — otherwise the pin in pkt. 3 could never
    catch a genuine new orchestration problem."""
    other = "GroupChatOrchestrator: participant 'checker' returned no message."
    assert _record_through_real_logger(other, quiet=True) == [other]


def test_the_demo_run_emits_no_round_cap_notice() -> None:
    """T-P4.2e: the damping is WIRED — the real demo process writes no round-cap line.

    Without this, the three asserts above would all pass with the ``main()`` call detached: they
    install the filter themselves, so they measure the filter and not the demo. Runs the module form
    (``-m``) rather than the console script, because that needs no assumption about PATH; both forms
    were measured to write identical stderr when the entry point was added, and the console script
    has its own tests in ``test_console_entry_points``.
    """
    proc = subprocess.run(
        [sys.executable, "-m", "portfolio_optimiser.simulation"],
        capture_output=True,
        text=True,
        check=False,
    )
    assert proc.returncode == 0, proc.stderr
    assert "forcing completion" not in proc.stderr, (
        "the round-cap notice reached stderr; is quiet_expected_round_cap_notice() still called in "
        f"main()? stderr was:\n{proc.stderr}"
    )
    # Control on the same output: the run really did happen, so the absence above is a damped line
    # and not an unrun demo.
    assert "LÆRINGSSLØYFA ER LUKKET" in proc.stdout


def test_damping_is_not_installed_at_import_time() -> None:
    """T-P4.2d: importing the module must not reconfigure logging for a library consumer — the
    filter is runtime state installed by ``main()``. RED if the install call is moved to module
    scope."""
    assert logging.getLogger(ROUND_CAP_LOGGER).filters == []