EvoScientist-Multi/tests/test_channel_debug.py

"""Tests for shared channel debug logging helpers."""

import asyncio
import logging
import threading
from unittest.mock import AsyncMock, MagicMock, patch

from EvoScientist.channels.debug import (
    TraceMixin,
    debug_trace_enabled,
    emit_debug_event,
    emit_debug_event_if,
)


def test_debug_trace_enabled_from_bool():
    assert debug_trace_enabled(True) is True
    assert debug_trace_enabled(False) is False


def test_emit_debug_event_structured(caplog):
    logger = logging.getLogger("tests.channel.debug")
    with caplog.at_level(logging.DEBUG, logger=logger.name):
        emit_debug_event(
            logger,
            "inbound_raw",
            channel="telegram",
            enabled=True,
            message_id="123",
            chat_id="-1001",
            has_text=True,
        )
    assert "event=inbound_raw" in caplog.text
    assert "channel=telegram" in caplog.text
    assert "message_id=123" in caplog.text
    assert "has_text=true" in caplog.text


# ── emit_debug_event_if tests ────────────────────────────────────────


def test_emit_debug_event_if_disabled_does_not_log(caplog):
    logger = logging.getLogger("tests.channel.event_if_disabled")
    with caplog.at_level(logging.DEBUG, logger=logger.name):
        emit_debug_event_if(
            logger,
            "should_not_appear",
            False,
            channel="test",
            key="value",
        )
    assert "should_not_appear" not in caplog.text


# ── Middleware structured event tests ────────────────────────────────


def _make_raw(**overrides):
    """Create a minimal RawIncoming for testing."""
    from EvoScientist.channels.base import RawIncoming

    defaults = {"sender_id": "user1", "chat_id": "chat1", "text": "hello"}
    defaults.update(overrides)
    return RawIncoming(**defaults)


def _make_channel_context(*, debug_trace=True, name="test_channel"):
    """Create a mock channel context dict for middleware testing."""
    channel = MagicMock()
    channel.name = name
    channel.is_debug_trace_enabled.return_value = debug_trace
    channel.config = MagicMock()
    channel.config.debug_trace = debug_trace
    return {"channel": channel}


async def test_middleware_dedup_emits_structured_event(caplog):
    from EvoScientist.channels.middleware import DedupMiddleware

    with caplog.at_level(logging.DEBUG):
        mw = DedupMiddleware()
        ctx = _make_channel_context()
        raw = _make_raw(message_id="dup1")

        # First call — not a duplicate
        result = await mw.process_inbound(raw, ctx)
        assert result is not None

        # Second call — duplicate, should emit structured event
        caplog.clear()
        result = await mw.process_inbound(raw, ctx)
        assert result is None
    assert "middleware_dedup_drop" in caplog.text
    assert "message_id=dup1" in caplog.text


async def test_middleware_allowlist_emits_structured_event(caplog):
    from EvoScientist.channels.middleware import AllowListMiddleware

    with caplog.at_level(logging.DEBUG):
        mw = AllowListMiddleware(allowed_senders={"allowed_user"})
        ctx = _make_channel_context()
        raw = _make_raw(sender_id="blocked_user")
        result = await mw.process_inbound(raw, ctx)
        assert result is None
    assert "middleware_allowlist_drop" in caplog.text
    assert "reason=sender_not_allowed" in caplog.text


async def test_middleware_mention_gating_emits_structured_event(caplog):
    from EvoScientist.channels.middleware import MentionGatingMiddleware

    with caplog.at_level(logging.DEBUG):
        mw = MentionGatingMiddleware(require_mention="group")
        ctx = _make_channel_context()
        raw = _make_raw(is_group=True, was_mentioned=False)
        result = await mw.process_inbound(raw, ctx)
        assert result is None
    assert "middleware_mention_drop" in caplog.text
    assert "policy=group" in caplog.text


async def test_typing_manager_emits_trace_events(caplog):
    from EvoScientist.channels.middleware import TypingManager

    with caplog.at_level(logging.DEBUG):
        send_action = AsyncMock(side_effect=RuntimeError("typing api down"))
        mgr = TypingManager(
            send_action,
            interval=100.0,
            debug_trace=True,
            channel_name="test",
        )
        await mgr.start("chat1")
        await asyncio.sleep(0.01)
        await mgr.stop("chat1")
    assert "typing_error" in caplog.text
    assert "chat_id=chat1" in caplog.text


async def test_ack_reaction_emits_error_traces(caplog):
    from EvoScientist.channels.middleware import AckReactionMiddleware

    with caplog.at_level(logging.DEBUG):
        send_fn = AsyncMock()
        remove_fn = AsyncMock(side_effect=RuntimeError("remove failed"))
        ack = AckReactionMiddleware(
            scope="all",
            send_fn=send_fn,
            remove_fn=remove_fn,
            remove_after_reply=True,
            debug_trace=True,
            channel_name="test",
        )

        # Successful send
        await ack.send_ack("chat1", "msg1")
        send_fn.assert_awaited_once()

        # Error on remove
        await ack.remove_ack("chat1")
        remove_fn.assert_awaited_once()

        # Error on send
        send_fn.reset_mock()
        send_fn.side_effect = RuntimeError("api down")
        await ack.send_ack("chat2", "msg2")
    assert "ack_send_error" in caplog.text
    assert "ack_remove_error" in caplog.text
    assert "api down" in caplog.text
    assert "remove failed" in caplog.text


async def test_inbound_raw_event_emitted(caplog):
    """Integration-style: _enqueue_raw emits inbound_raw at the top."""
    from EvoScientist.channels.base import Channel, RawIncoming

    # Create a minimal concrete channel
    class _TestChannel(Channel):
        name = "test_inbound"
        capabilities = MagicMock()
        capabilities.max_text_length = 4096
        capabilities.format_type = "markdown"

        async def start(self):
            pass

        async def _send_chunk(self, chat_id, formatted, raw, reply_to, metadata):
            pass

    config = MagicMock()
    config.debug_trace = True
    config.debug_payloads = False
    config.text_chunk_limit = 0
    config.stt_enabled = False
    config.inbound_middlewares = []
    config.name = "test_inbound"
    config.require_mention = "off"
    config.allowed_senders = None
    config.allowed_channels = None
    config.dm_policy = "open"
    config.ack_scope = "off"
    config.dedup_ttl = 3600

    with caplog.at_level(logging.DEBUG):
        with patch.object(Channel, "__abstractmethods__", set()):
            ch = _TestChannel(config)
        raw = RawIncoming(sender_id="u1", chat_id="c1", text="hi", message_id="m1")
        await ch._enqueue_raw(raw)
    assert "inbound_raw" in caplog.text
    assert "sender_id=u1" in caplog.text


async def test_format_fallback_emits_event(caplog):
    """_send_with_format_fallback emits outbound_format_fallback on fallback."""
    from EvoScientist.channels.base import Channel

    class _TestChannel(Channel):
        name = "test_fallback"
        capabilities = MagicMock()
        capabilities.max_text_length = 4096
        capabilities.format_type = "markdown"

        async def start(self):
            pass

        async def _send_chunk(self, chat_id, formatted, raw, reply_to, metadata):
            pass

    config = MagicMock()
    config.debug_trace = True
    config.debug_payloads = False
    config.text_chunk_limit = 0
    config.stt_enabled = False
    config.inbound_middlewares = []
    config.name = "test_fallback"
    config.require_mention = "off"
    config.allowed_senders = None
    config.allowed_channels = None
    config.dm_policy = "open"
    config.ack_scope = "off"
    config.dedup_ttl = 3600

    call_count = 0

    async def _failing_send(text):
        nonlocal call_count
        call_count += 1
        if call_count == 1:
            raise ValueError("parse error in formatted text")

    with caplog.at_level(logging.DEBUG):
        with patch.object(Channel, "__abstractmethods__", set()):
            ch = _TestChannel(config)
        await ch._send_with_format_fallback(_failing_send, "<b>hi</b>", "hi")
    assert "outbound_format_fallback" in caplog.text
    assert call_count == 2


# ── TraceMixin tests ─────────────────────────────────────────────────


def _make_trace_stub(logger_name: str = "tests.mixin") -> TraceMixin:
    """Create a minimal TraceMixin instance for testing."""

    class _Stub(TraceMixin):
        name = "stub"

        def __init__(self):
            self._debug_trace = True
            self._trace_logger = logging.getLogger(logger_name)

    return _Stub()


def test_trace_mixin_trace_event(caplog):
    stub = _make_trace_stub("tests.mixin")
    with caplog.at_level(logging.DEBUG, logger="tests.mixin"):
        stub._trace_event("some_event", key="val")
    assert "event=some_event" in caplog.text
    assert "channel=stub" in caplog.text
    assert "key=val" in caplog.text


async def test_standalone_dispatcher_treats_false_send_as_error(caplog):
    from EvoScientist.channels.bus import MessageBus
    from EvoScientist.channels.bus.events import OutboundMessage
    from EvoScientist.channels.standalone import standalone_outbound_dispatcher

    channel = MagicMock()
    channel.name = "test"
    channel.is_debug_trace_enabled.return_value = True
    channel.send = AsyncMock(return_value=False)
    bus = MessageBus()

    with caplog.at_level(logging.DEBUG):
        task = asyncio.create_task(standalone_outbound_dispatcher(bus, channel))
        await bus.publish_outbound(
            OutboundMessage(channel="test", chat_id="c1", content="hi")
        )
        await asyncio.sleep(0.05)
        task.cancel()
        try:
            await task
        except asyncio.CancelledError:
            pass
    assert "standalone_dispatch_error" in caplog.text
    assert "send() returned False" in caplog.text


async def test_standalone_dispatcher_sends_media():
    from EvoScientist.channels.bus import MessageBus
    from EvoScientist.channels.bus.events import OutboundMessage
    from EvoScientist.channels.standalone import standalone_outbound_dispatcher

    channel = MagicMock()
    channel.name = "test"
    channel.is_debug_trace_enabled.return_value = True
    channel.send = AsyncMock(return_value=True)
    channel.send_media = AsyncMock(return_value=True)
    bus = MessageBus()

    task = asyncio.create_task(standalone_outbound_dispatcher(bus, channel))
    await bus.publish_outbound(
        OutboundMessage(channel="test", chat_id="c1", content="", media=["/tmp/a.png"])
    )
    await asyncio.sleep(0.05)
    task.cancel()
    try:
        await task
    except asyncio.CancelledError:
        pass
    channel.send_media.assert_awaited_once_with(
        recipient="c1",
        file_path="/tmp/a.png",
        metadata={},
    )


# ── One-time warning test ────────────────────────────────────────────


def test_emit_debug_event_warns_on_level_mismatch(caplog):
    import EvoScientist.channels.debug as dbg

    # Reset the global warning flag
    dbg._warned_debug_level_mismatch = False
    logger = logging.getLogger("tests.level_mismatch")
    # Logger at WARNING — higher than DEBUG
    with caplog.at_level(logging.WARNING, logger=logger.name):
        emit_debug_event(logger, "should_warn", channel="test", enabled=True, x=1)
        emit_debug_event(logger, "should_not_warn_again", channel="test", enabled=True)

    # Should see the one-time mismatch warning
    warnings = [r for r in caplog.records if r.levelno == logging.WARNING]
    mismatch_warnings = [r for r in warnings if "debug tracing is enabled" in r.message]
    assert len(mismatch_warnings) == 1
    # Should NOT see the actual debug events
    assert "should_warn" not in caplog.text or "event=should_warn" not in caplog.text

    # Reset for other tests
    dbg._warned_debug_level_mismatch = False


async def test_standalone_agent_construction_runs_off_channel_loop(monkeypatch):
    import EvoScientist.EvoScientist as agent_module
    from EvoScientist.channels.standalone import _create_standalone_agent

    channel_thread = threading.current_thread()
    sentinel = object()

    def fake_create_cli_agent():
        assert threading.current_thread() is not channel_thread
        try:
            asyncio.get_running_loop()
        except RuntimeError:
            pass
        else:  # pragma: no cover - assertion branch
            raise AssertionError("agent construction inherited the channel loop")
        return sentinel

    monkeypatch.setattr(agent_module, "create_cli_agent", fake_create_cli_agent)

    assert await _create_standalone_agent() is sentinel